mirror of
https://github.com/k3s-io/kubernetes.git
synced 2025-07-21 10:51:29 +00:00
logging: add ContextualLogging feature
InitLogs overrides the klog default and turns contextual logging off. This ensures that it is only enabled in Kubernetes commands that explicitly enable it via a feature gate. A feature gate for it gets defined in k8s.io/component-base/logs and is then used by Options.ValidateAndApply. The effect of disabling contextual logging is very limited according to benchmarks with kube-scheduler. The feature gets added anyway to satisfy the PRR recommendation that features should be controllable. The following commands have support for contextual logging: - kube-apiserver - kube-controller-manager - kubelet - kube-scheduler - component-base/logs example Supporting a feature gate check in ValidateAndApply and not in InitLogs is a simplification: changing InitLogs to accept a FeatureGate would have implied changing also component-base/cli.Run. This didn't seem worthwhile because ValidateAndApply already covers the relevant commands.
This commit is contained in:
parent
b390d018c7
commit
7de1b05e85
@ -34,6 +34,7 @@ import (
|
|||||||
extensionsapiserver "k8s.io/apiextensions-apiserver/pkg/apiserver"
|
extensionsapiserver "k8s.io/apiextensions-apiserver/pkg/apiserver"
|
||||||
utilerrors "k8s.io/apimachinery/pkg/util/errors"
|
utilerrors "k8s.io/apimachinery/pkg/util/errors"
|
||||||
utilnet "k8s.io/apimachinery/pkg/util/net"
|
utilnet "k8s.io/apimachinery/pkg/util/net"
|
||||||
|
utilruntime "k8s.io/apimachinery/pkg/util/runtime"
|
||||||
"k8s.io/apimachinery/pkg/util/sets"
|
"k8s.io/apimachinery/pkg/util/sets"
|
||||||
"k8s.io/apiserver/pkg/admission"
|
"k8s.io/apiserver/pkg/admission"
|
||||||
"k8s.io/apiserver/pkg/authorization/authorizer"
|
"k8s.io/apiserver/pkg/authorization/authorizer"
|
||||||
@ -80,6 +81,10 @@ import (
|
|||||||
"k8s.io/kubernetes/pkg/serviceaccount"
|
"k8s.io/kubernetes/pkg/serviceaccount"
|
||||||
)
|
)
|
||||||
|
|
||||||
|
func init() {
|
||||||
|
utilruntime.Must(logs.AddFeatureGates(utilfeature.DefaultMutableFeatureGate))
|
||||||
|
}
|
||||||
|
|
||||||
// NewAPIServerCommand creates a *cobra.Command object with default parameters
|
// NewAPIServerCommand creates a *cobra.Command object with default parameters
|
||||||
func NewAPIServerCommand() *cobra.Command {
|
func NewAPIServerCommand() *cobra.Command {
|
||||||
s := options.NewServerRunOptions()
|
s := options.NewServerRunOptions()
|
||||||
@ -104,7 +109,7 @@ cluster's shared state through which all other components interact.`,
|
|||||||
|
|
||||||
// Activate logging as soon as possible, after that
|
// Activate logging as soon as possible, after that
|
||||||
// show flags with the final logging configuration.
|
// show flags with the final logging configuration.
|
||||||
if err := s.Logs.ValidateAndApply(); err != nil {
|
if err := s.Logs.ValidateAndApply(utilfeature.DefaultFeatureGate); err != nil {
|
||||||
return err
|
return err
|
||||||
}
|
}
|
||||||
cliflag.PrintFlags(fs)
|
cliflag.PrintFlags(fs)
|
||||||
|
@ -73,6 +73,10 @@ import (
|
|||||||
"k8s.io/kubernetes/pkg/serviceaccount"
|
"k8s.io/kubernetes/pkg/serviceaccount"
|
||||||
)
|
)
|
||||||
|
|
||||||
|
func init() {
|
||||||
|
utilruntime.Must(logs.AddFeatureGates(utilfeature.DefaultMutableFeatureGate))
|
||||||
|
}
|
||||||
|
|
||||||
const (
|
const (
|
||||||
// ControllerStartJitter is the Jitter used when starting controller managers
|
// ControllerStartJitter is the Jitter used when starting controller managers
|
||||||
ControllerStartJitter = 1.0
|
ControllerStartJitter = 1.0
|
||||||
@ -118,7 +122,7 @@ controller, and serviceaccounts controller.`,
|
|||||||
|
|
||||||
// Activate logging as soon as possible, after that
|
// Activate logging as soon as possible, after that
|
||||||
// show flags with the final logging configuration.
|
// show flags with the final logging configuration.
|
||||||
if err := s.Logs.ValidateAndApply(); err != nil {
|
if err := s.Logs.ValidateAndApply(utilfeature.DefaultFeatureGate); err != nil {
|
||||||
fmt.Fprintf(os.Stderr, "%v\n", err)
|
fmt.Fprintf(os.Stderr, "%v\n", err)
|
||||||
os.Exit(1)
|
os.Exit(1)
|
||||||
}
|
}
|
||||||
|
@ -27,6 +27,7 @@ import (
|
|||||||
"github.com/spf13/cobra"
|
"github.com/spf13/cobra"
|
||||||
|
|
||||||
utilerrors "k8s.io/apimachinery/pkg/util/errors"
|
utilerrors "k8s.io/apimachinery/pkg/util/errors"
|
||||||
|
utilruntime "k8s.io/apimachinery/pkg/util/runtime"
|
||||||
"k8s.io/apiserver/pkg/authentication/authenticator"
|
"k8s.io/apiserver/pkg/authentication/authenticator"
|
||||||
"k8s.io/apiserver/pkg/authorization/authorizer"
|
"k8s.io/apiserver/pkg/authorization/authorizer"
|
||||||
genericapifilters "k8s.io/apiserver/pkg/endpoints/filters"
|
genericapifilters "k8s.io/apiserver/pkg/endpoints/filters"
|
||||||
@ -36,6 +37,7 @@ import (
|
|||||||
"k8s.io/apiserver/pkg/server/healthz"
|
"k8s.io/apiserver/pkg/server/healthz"
|
||||||
"k8s.io/apiserver/pkg/server/mux"
|
"k8s.io/apiserver/pkg/server/mux"
|
||||||
"k8s.io/apiserver/pkg/server/routes"
|
"k8s.io/apiserver/pkg/server/routes"
|
||||||
|
utilfeature "k8s.io/apiserver/pkg/util/feature"
|
||||||
"k8s.io/client-go/informers"
|
"k8s.io/client-go/informers"
|
||||||
"k8s.io/client-go/kubernetes/scheme"
|
"k8s.io/client-go/kubernetes/scheme"
|
||||||
"k8s.io/client-go/tools/events"
|
"k8s.io/client-go/tools/events"
|
||||||
@ -59,6 +61,10 @@ import (
|
|||||||
"k8s.io/kubernetes/pkg/scheduler/profile"
|
"k8s.io/kubernetes/pkg/scheduler/profile"
|
||||||
)
|
)
|
||||||
|
|
||||||
|
func init() {
|
||||||
|
utilruntime.Must(logs.AddFeatureGates(utilfeature.DefaultMutableFeatureGate))
|
||||||
|
}
|
||||||
|
|
||||||
// Option configures a framework.Registry.
|
// Option configures a framework.Registry.
|
||||||
type Option func(runtime.Registry) error
|
type Option func(runtime.Registry) error
|
||||||
|
|
||||||
@ -113,7 +119,7 @@ func runCommand(cmd *cobra.Command, opts *options.Options, registryOptions ...Op
|
|||||||
|
|
||||||
// Activate logging as soon as possible, after that
|
// Activate logging as soon as possible, after that
|
||||||
// show flags with the final logging configuration.
|
// show flags with the final logging configuration.
|
||||||
if err := opts.Logs.ValidateAndApply(); err != nil {
|
if err := opts.Logs.ValidateAndApply(utilfeature.DefaultFeatureGate); err != nil {
|
||||||
fmt.Fprintf(os.Stderr, "%v\n", err)
|
fmt.Fprintf(os.Stderr, "%v\n", err)
|
||||||
os.Exit(1)
|
os.Exit(1)
|
||||||
}
|
}
|
||||||
|
@ -45,6 +45,7 @@ import (
|
|||||||
"k8s.io/apimachinery/pkg/runtime"
|
"k8s.io/apimachinery/pkg/runtime"
|
||||||
"k8s.io/apimachinery/pkg/types"
|
"k8s.io/apimachinery/pkg/types"
|
||||||
utilnet "k8s.io/apimachinery/pkg/util/net"
|
utilnet "k8s.io/apimachinery/pkg/util/net"
|
||||||
|
utilruntime "k8s.io/apimachinery/pkg/util/runtime"
|
||||||
"k8s.io/apimachinery/pkg/util/sets"
|
"k8s.io/apimachinery/pkg/util/sets"
|
||||||
"k8s.io/apimachinery/pkg/util/wait"
|
"k8s.io/apimachinery/pkg/util/wait"
|
||||||
genericapiserver "k8s.io/apiserver/pkg/server"
|
genericapiserver "k8s.io/apiserver/pkg/server"
|
||||||
@ -103,6 +104,10 @@ import (
|
|||||||
netutils "k8s.io/utils/net"
|
netutils "k8s.io/utils/net"
|
||||||
)
|
)
|
||||||
|
|
||||||
|
func init() {
|
||||||
|
utilruntime.Must(logs.AddFeatureGates(utilfeature.DefaultMutableFeatureGate))
|
||||||
|
}
|
||||||
|
|
||||||
const (
|
const (
|
||||||
// Kubelet component name
|
// Kubelet component name
|
||||||
componentKubelet = "kubelet"
|
componentKubelet = "kubelet"
|
||||||
@ -226,7 +231,7 @@ HTTP server: The kubelet can also listen for HTTP and respond to a simple API
|
|||||||
// Config and flags parsed, now we can initialize logging.
|
// Config and flags parsed, now we can initialize logging.
|
||||||
logs.InitLogs()
|
logs.InitLogs()
|
||||||
logOption := &logs.Options{Config: kubeletConfig.Logging}
|
logOption := &logs.Options{Config: kubeletConfig.Logging}
|
||||||
if err := logOption.ValidateAndApply(); err != nil {
|
if err := logOption.ValidateAndApply(utilfeature.DefaultFeatureGate); err != nil {
|
||||||
klog.ErrorS(err, "Failed to initialize logging")
|
klog.ErrorS(err, "Failed to initialize logging")
|
||||||
os.Exit(1)
|
os.Exit(1)
|
||||||
}
|
}
|
||||||
|
@ -13,11 +13,18 @@ go run ./staging/src/k8s.io/component-base/logs/example/cmd/logger.go
|
|||||||
|
|
||||||
Expected output:
|
Expected output:
|
||||||
```
|
```
|
||||||
I0605 22:03:07.224293 3228948 logger.go:58] Log using Infof, key: value
|
I0329 11:36:38.734334 99095 logger.go:44] "Oops, I shouldn't be logging yet!"
|
||||||
I0605 22:03:07.224378 3228948 logger.go:59] "Log using InfoS" key="value"
|
This is normal output via stdout.
|
||||||
E0605 22:03:07.224393 3228948 logger.go:61] Log using Errorf, err: fail
|
This is other output via stderr.
|
||||||
E0605 22:03:07.224402 3228948 logger.go:62] "Log using ErrorS" err="fail"
|
I0329 11:36:38.734575 99095 logger.go:76] Log using Infof, key: value
|
||||||
I0605 22:03:07.224407 3228948 logger.go:64] Log message has been redacted. Log argument #0 contains: [secret-key]
|
I0329 11:36:38.734592 99095 logger.go:77] "Log using InfoS" key="value"
|
||||||
|
E0329 11:36:38.734604 99095 logger.go:79] Log using Errorf, err: fail
|
||||||
|
E0329 11:36:38.734619 99095 logger.go:80] "Log using ErrorS" err="fail"
|
||||||
|
I0329 11:36:38.734631 99095 logger.go:82] Log with sensitive key, data: {"secret"}
|
||||||
|
I0329 11:36:38.734653 99095 logger.go:87] "Now the default logger is set, but using the one from the context is still better."
|
||||||
|
I0329 11:36:38.734674 99095 logger.go:90] "Log sensitive data through context" data={Key:secret}
|
||||||
|
I0329 11:36:38.734693 99095 logger.go:94] "runtime" duration="1m0s"
|
||||||
|
I0329 11:36:38.734710 99095 logger.go:95] "another runtime" duration="1m0s"
|
||||||
```
|
```
|
||||||
|
|
||||||
## JSON
|
## JSON
|
||||||
@ -29,11 +36,18 @@ go run ./staging/src/k8s.io/component-base/logs/example/cmd/logger.go --logging-
|
|||||||
|
|
||||||
Expected output:
|
Expected output:
|
||||||
```
|
```
|
||||||
{"ts":1624215726270.3562,"caller":"cmd/logger.go:58","msg":"Log using Infof, key: value\n","v":0}
|
I0329 11:38:01.782592 99945 logger.go:44] "Oops, I shouldn't be logging yet!"
|
||||||
{"ts":1624215726270.4377,"caller":"cmd/logger.go:59","msg":"Log using InfoS","v":0,"key":"value"}
|
This is normal output via stdout.
|
||||||
{"ts":1624215726270.6724,"caller":"cmd/logger.go:61","msg":"Log using Errorf, err: fail\n","v":0}
|
This is other output via stderr.
|
||||||
{"ts":1624215726270.7566,"caller":"cmd/logger.go:62","msg":"Log using ErrorS","err":"fail","v":0}
|
{"ts":1648546681782.9036,"caller":"cmd/logger.go:76","msg":"Log using Infof, key: value\n","v":0}
|
||||||
{"ts":1624215726270.8428,"caller":"cmd/logger.go:64","msg":"Log with sensitive key, data: {\"secret\"}\n","v":0}
|
{"ts":1648546681782.9392,"caller":"cmd/logger.go:77","msg":"Log using InfoS","v":0,"key":"value"}
|
||||||
|
{"ts":1648546681782.9763,"caller":"cmd/logger.go:79","msg":"Log using Errorf, err: fail\n"}
|
||||||
|
{"ts":1648546681782.9915,"caller":"cmd/logger.go:80","msg":"Log using ErrorS","err":"fail"}
|
||||||
|
{"ts":1648546681783.0208,"caller":"cmd/logger.go:82","msg":"Log with sensitive key, data: {\"secret\"}\n","v":0}
|
||||||
|
{"ts":1648546681783.0364,"caller":"cmd/logger.go:87","msg":"Now the default logger is set, but using the one from the context is still better.","v":0}
|
||||||
|
{"ts":1648546681783.0552,"caller":"cmd/logger.go:90","msg":"Log sensitive data through context","v":0,"data":{"key":"secret"}}
|
||||||
|
{"ts":1648546681783.1091,"caller":"cmd/logger.go:94","msg":"runtime","v":0,"duration":"1m0s"}
|
||||||
|
{"ts":1648546681783.1257,"caller":"cmd/logger.go:95","msg":"another runtime","v":0,"duration":"1h0m0s","duration":"1m0s"}
|
||||||
```
|
```
|
||||||
|
|
||||||
## Verbosity
|
## Verbosity
|
||||||
@ -42,13 +56,53 @@ Expected output:
|
|||||||
go run ./staging/src/k8s.io/component-base/logs/example/cmd/logger.go -v1
|
go run ./staging/src/k8s.io/component-base/logs/example/cmd/logger.go -v1
|
||||||
```
|
```
|
||||||
|
|
||||||
|
The expected output now includes `Log less important message`:
|
||||||
```
|
```
|
||||||
I0914 10:31:12.342958 54086 logger.go:61] Log using Infof, key: value
|
I0329 11:38:23.145695 100190 logger.go:44] "Oops, I shouldn't be logging yet!"
|
||||||
I0914 10:31:12.343021 54086 logger.go:62] "Log using InfoS" key="value"
|
This is normal output via stdout.
|
||||||
E0914 10:31:12.343053 54086 logger.go:64] Log using Errorf, err: fail
|
This is other output via stderr.
|
||||||
E0914 10:31:12.343064 54086 logger.go:65] "Log using ErrorS" err="fail"
|
I0329 11:38:23.145944 100190 logger.go:76] Log using Infof, key: value
|
||||||
I0914 10:31:12.343073 54086 logger.go:67] Log with sensitive key, data: {"secret"}
|
I0329 11:38:23.145961 100190 logger.go:77] "Log using InfoS" key="value"
|
||||||
I0914 10:31:12.343090 54086 logger.go:68] Log less important message
|
E0329 11:38:23.145973 100190 logger.go:79] Log using Errorf, err: fail
|
||||||
|
E0329 11:38:23.145989 100190 logger.go:80] "Log using ErrorS" err="fail"
|
||||||
|
I0329 11:38:23.146000 100190 logger.go:82] Log with sensitive key, data: {"secret"}
|
||||||
|
I0329 11:38:23.146017 100190 logger.go:83] Log less important message
|
||||||
|
I0329 11:38:23.146034 100190 logger.go:87] "Now the default logger is set, but using the one from the context is still better."
|
||||||
|
I0329 11:38:23.146055 100190 logger.go:90] "Log sensitive data through context" data={Key:secret}
|
||||||
|
I0329 11:38:23.146074 100190 logger.go:94] "runtime" duration="1m0s"
|
||||||
|
I0329 11:38:23.146091 100190 logger.go:95] "another runtime" duration="1m0s"
|
||||||
```
|
```
|
||||||
|
|
||||||
The last line is not printed at the default log level.
|
## Contextual logging
|
||||||
|
|
||||||
|
Contextual logging enables the caller of the function to add a string prefix
|
||||||
|
and additional key/value pairs to a logger and then pass the updated logger
|
||||||
|
into functions via a `context` parameter.
|
||||||
|
|
||||||
|
At the moment, this functionality is controlled in Kubernetes with the
|
||||||
|
`ContextualLogging` feature gate and disabled by
|
||||||
|
default. `klog.LoggerWithValues`, `klog.LoggerWithName`, `klog.NewContext` just
|
||||||
|
return the original instance when contextual logging is
|
||||||
|
disabled. `klog.FromContext` doesn't check the context for a logger and instead
|
||||||
|
returns the global logger.
|
||||||
|
|
||||||
|
```console
|
||||||
|
go run ./staging/src/k8s.io/component-base/logs/example/cmd/logger.go --feature-gates ContextualLogging=true
|
||||||
|
```
|
||||||
|
|
||||||
|
The expected output now includes `example` (added by caller) and `myname`
|
||||||
|
(added by callee) as prefix and the caller's `foo="bar"` key/value pair:
|
||||||
|
```
|
||||||
|
I0329 11:47:36.830458 101057 logger.go:44] "Oops, I shouldn't be logging yet!"
|
||||||
|
This is normal output via stdout.
|
||||||
|
This is other output via stderr.
|
||||||
|
I0329 11:47:36.830715 101057 logger.go:76] Log using Infof, key: value
|
||||||
|
I0329 11:47:36.830731 101057 logger.go:77] "Log using InfoS" key="value"
|
||||||
|
E0329 11:47:36.830745 101057 logger.go:79] Log using Errorf, err: fail
|
||||||
|
E0329 11:47:36.830760 101057 logger.go:80] "Log using ErrorS" err="fail"
|
||||||
|
I0329 11:47:36.830772 101057 logger.go:82] Log with sensitive key, data: {"secret"}
|
||||||
|
I0329 11:47:36.830795 101057 logger.go:87] "Now the default logger is set, but using the one from the context is still better."
|
||||||
|
I0329 11:47:36.830818 101057 logger.go:90] "example: Log sensitive data through context" foo="bar" data={Key:secret}
|
||||||
|
I0329 11:47:36.830841 101057 logger.go:94] "example/myname: runtime" foo="bar" duration="1m0s"
|
||||||
|
I0329 11:47:36.830859 101057 logger.go:95] "example: another runtime" foo="bar" duration="1m0s"
|
||||||
|
```
|
||||||
|
@ -17,21 +17,32 @@ limitations under the License.
|
|||||||
package main
|
package main
|
||||||
|
|
||||||
import (
|
import (
|
||||||
|
"context"
|
||||||
"errors"
|
"errors"
|
||||||
"fmt"
|
"fmt"
|
||||||
"os"
|
"os"
|
||||||
|
"time"
|
||||||
|
|
||||||
"github.com/spf13/cobra"
|
"github.com/spf13/cobra"
|
||||||
|
|
||||||
|
"k8s.io/apimachinery/pkg/util/runtime"
|
||||||
"k8s.io/component-base/cli"
|
"k8s.io/component-base/cli"
|
||||||
|
"k8s.io/component-base/featuregate"
|
||||||
"k8s.io/component-base/logs"
|
"k8s.io/component-base/logs"
|
||||||
"k8s.io/klog/v2"
|
"k8s.io/klog/v2"
|
||||||
|
|
||||||
_ "k8s.io/component-base/logs/json/register"
|
_ "k8s.io/component-base/logs/json/register"
|
||||||
)
|
)
|
||||||
|
|
||||||
|
var featureGate = featuregate.NewFeatureGate()
|
||||||
|
|
||||||
func main() {
|
func main() {
|
||||||
|
runtime.Must(logs.AddFeatureGates(featureGate))
|
||||||
command := NewLoggerCommand()
|
command := NewLoggerCommand()
|
||||||
|
|
||||||
|
// Intentionally broken: logging is not initialized yet.
|
||||||
|
klog.TODO().Info("Oops, I shouldn't be logging yet!")
|
||||||
|
|
||||||
code := cli.Run(command)
|
code := cli.Run(command)
|
||||||
os.Exit(code)
|
os.Exit(code)
|
||||||
}
|
}
|
||||||
@ -40,18 +51,26 @@ func NewLoggerCommand() *cobra.Command {
|
|||||||
o := logs.NewOptions()
|
o := logs.NewOptions()
|
||||||
cmd := &cobra.Command{
|
cmd := &cobra.Command{
|
||||||
Run: func(cmd *cobra.Command, args []string) {
|
Run: func(cmd *cobra.Command, args []string) {
|
||||||
if err := o.ValidateAndApply(); err != nil {
|
logs.InitLogs()
|
||||||
|
if err := o.ValidateAndApply(featureGate); err != nil {
|
||||||
fmt.Fprintf(os.Stderr, "%v\n", err)
|
fmt.Fprintf(os.Stderr, "%v\n", err)
|
||||||
os.Exit(1)
|
os.Exit(1)
|
||||||
}
|
}
|
||||||
runLogger()
|
|
||||||
|
// Initialize contextual logging.
|
||||||
|
logger := klog.Background().WithName("example").WithValues("foo", "bar")
|
||||||
|
ctx := klog.NewContext(context.Background(), logger)
|
||||||
|
|
||||||
|
runLogger(ctx)
|
||||||
},
|
},
|
||||||
}
|
}
|
||||||
|
logs.AddFeatureGates(featureGate)
|
||||||
|
featureGate.AddFlag(cmd.Flags())
|
||||||
o.AddFlags(cmd.Flags())
|
o.AddFlags(cmd.Flags())
|
||||||
return cmd
|
return cmd
|
||||||
}
|
}
|
||||||
|
|
||||||
func runLogger() {
|
func runLogger(ctx context.Context) {
|
||||||
fmt.Println("This is normal output via stdout.")
|
fmt.Println("This is normal output via stdout.")
|
||||||
fmt.Fprintln(os.Stderr, "This is other output via stderr.")
|
fmt.Fprintln(os.Stderr, "This is other output via stderr.")
|
||||||
klog.Infof("Log using Infof, key: %s", "value")
|
klog.Infof("Log using Infof, key: %s", "value")
|
||||||
@ -62,6 +81,18 @@ func runLogger() {
|
|||||||
data := SensitiveData{Key: "secret"}
|
data := SensitiveData{Key: "secret"}
|
||||||
klog.Infof("Log with sensitive key, data: %q", data)
|
klog.Infof("Log with sensitive key, data: %q", data)
|
||||||
klog.V(1).Info("Log less important message")
|
klog.V(1).Info("Log less important message")
|
||||||
|
|
||||||
|
// This is the fallback that can be used if neither logger nor context
|
||||||
|
// are available... but it's better to pass some kind of parameter.
|
||||||
|
klog.TODO().Info("Now the default logger is set, but using the one from the context is still better.")
|
||||||
|
|
||||||
|
logger := klog.FromContext(ctx)
|
||||||
|
logger.Info("Log sensitive data through context", "data", data)
|
||||||
|
|
||||||
|
// This intentionally uses the same key/value multiple times. Only the
|
||||||
|
// second example could be detected via static code analysis.
|
||||||
|
klog.LoggerWithValues(klog.LoggerWithName(logger, "myname"), "duration", time.Hour).Info("runtime", "duration", time.Minute)
|
||||||
|
logger.Info("another runtime", "duration", time.Hour, "duration", time.Minute)
|
||||||
}
|
}
|
||||||
|
|
||||||
type SensitiveData struct {
|
type SensitiveData struct {
|
||||||
|
@ -22,9 +22,12 @@ import (
|
|||||||
|
|
||||||
"github.com/spf13/pflag"
|
"github.com/spf13/pflag"
|
||||||
"github.com/stretchr/testify/assert"
|
"github.com/stretchr/testify/assert"
|
||||||
|
"github.com/stretchr/testify/require"
|
||||||
|
|
||||||
"k8s.io/apimachinery/pkg/util/validation/field"
|
"k8s.io/apimachinery/pkg/util/validation/field"
|
||||||
|
"k8s.io/component-base/featuregate"
|
||||||
"k8s.io/component-base/logs"
|
"k8s.io/component-base/logs"
|
||||||
|
"k8s.io/klog/v2"
|
||||||
)
|
)
|
||||||
|
|
||||||
func TestJSONFlag(t *testing.T) {
|
func TestJSONFlag(t *testing.T) {
|
||||||
@ -42,11 +45,13 @@ func TestJSONFlag(t *testing.T) {
|
|||||||
|
|
||||||
func TestJSONFormatRegister(t *testing.T) {
|
func TestJSONFormatRegister(t *testing.T) {
|
||||||
newOptions := logs.NewOptions()
|
newOptions := logs.NewOptions()
|
||||||
|
klogr := klog.Background()
|
||||||
testcases := []struct {
|
testcases := []struct {
|
||||||
name string
|
name string
|
||||||
args []string
|
args []string
|
||||||
want *logs.Options
|
contextualLogging bool
|
||||||
errs field.ErrorList
|
want *logs.Options
|
||||||
|
errs field.ErrorList
|
||||||
}{
|
}{
|
||||||
{
|
{
|
||||||
name: "JSON log format",
|
name: "JSON log format",
|
||||||
@ -57,6 +62,16 @@ func TestJSONFormatRegister(t *testing.T) {
|
|||||||
return &logs.Options{*c}
|
return &logs.Options{*c}
|
||||||
}(),
|
}(),
|
||||||
},
|
},
|
||||||
|
{
|
||||||
|
name: "JSON direct",
|
||||||
|
args: []string{"--logging-format=json"},
|
||||||
|
contextualLogging: true,
|
||||||
|
want: func() *logs.Options {
|
||||||
|
c := newOptions.Config.DeepCopy()
|
||||||
|
c.Format = logs.JSONLogFormat
|
||||||
|
return &logs.Options{*c}
|
||||||
|
}(),
|
||||||
|
},
|
||||||
{
|
{
|
||||||
name: "Unsupported log format",
|
name: "Unsupported log format",
|
||||||
args: []string{"--logging-format=test"},
|
args: []string{"--logging-format=test"},
|
||||||
@ -83,11 +98,24 @@ func TestJSONFormatRegister(t *testing.T) {
|
|||||||
if !assert.Equal(t, tc.want, o) {
|
if !assert.Equal(t, tc.want, o) {
|
||||||
t.Errorf("Wrong Validate() result for %q. expect %v, got %v", tc.name, tc.want, o)
|
t.Errorf("Wrong Validate() result for %q. expect %v, got %v", tc.name, tc.want, o)
|
||||||
}
|
}
|
||||||
errs := o.ValidateAndApply()
|
featureGate := featuregate.NewFeatureGate()
|
||||||
|
logs.AddFeatureGates(featureGate)
|
||||||
|
err := featureGate.SetFromMap(map[string]bool{string(logs.ContextualLogging): tc.contextualLogging})
|
||||||
|
require.NoError(t, err)
|
||||||
|
errs := o.ValidateAndApply(featureGate)
|
||||||
|
defer klog.ClearLogger()
|
||||||
if !assert.ElementsMatch(t, tc.errs, errs) {
|
if !assert.ElementsMatch(t, tc.errs, errs) {
|
||||||
t.Errorf("Wrong Validate() result for %q.\n expect:\t%+v\n got:\t%+v", tc.name, tc.errs, errs)
|
t.Errorf("Wrong Validate() result for %q.\n expect:\t%+v\n got:\t%+v", tc.name, tc.errs, errs)
|
||||||
|
|
||||||
}
|
}
|
||||||
|
currentLogger := klog.Background()
|
||||||
|
isKlogr := currentLogger == klogr
|
||||||
|
if tc.contextualLogging && isKlogr {
|
||||||
|
t.Errorf("Expected to get zapr as logger, got: %T", currentLogger)
|
||||||
|
}
|
||||||
|
if !tc.contextualLogging && !isKlogr {
|
||||||
|
t.Errorf("Expected to get klogr as logger, got: %T", currentLogger)
|
||||||
|
}
|
||||||
})
|
})
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
47
staging/src/k8s.io/component-base/logs/kube_features.go
Normal file
47
staging/src/k8s.io/component-base/logs/kube_features.go
Normal file
@ -0,0 +1,47 @@
|
|||||||
|
/*
|
||||||
|
Copyright 2021 The Kubernetes Authors.
|
||||||
|
|
||||||
|
Licensed under the Apache License, Version 2.0 (the "License");
|
||||||
|
you may not use this file except in compliance with the License.
|
||||||
|
You may obtain a copy of the License at
|
||||||
|
|
||||||
|
http://www.apache.org/licenses/LICENSE-2.0
|
||||||
|
|
||||||
|
Unless required by applicable law or agreed to in writing, software
|
||||||
|
distributed under the License is distributed on an "AS IS" BASIS,
|
||||||
|
WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
|
||||||
|
See the License for the specific language governing permissions and
|
||||||
|
limitations under the License.
|
||||||
|
*/
|
||||||
|
|
||||||
|
package logs
|
||||||
|
|
||||||
|
import (
|
||||||
|
"k8s.io/component-base/featuregate"
|
||||||
|
)
|
||||||
|
|
||||||
|
const (
|
||||||
|
// owner: @pohly
|
||||||
|
// kep: http://kep.k8s.io/3077
|
||||||
|
// alpha: v1.24
|
||||||
|
//
|
||||||
|
// Enables looking up a logger from a context.Context instead of using
|
||||||
|
// the global fallback logger and manipulating the logger that is
|
||||||
|
// used by a call chain.
|
||||||
|
ContextualLogging featuregate.Feature = "ContextualLogging"
|
||||||
|
|
||||||
|
// contextualLoggingDefault must remain false while in alpha. It can
|
||||||
|
// become true in beta.
|
||||||
|
contextualLoggingDefault = false
|
||||||
|
)
|
||||||
|
|
||||||
|
func featureGates() map[featuregate.Feature]featuregate.FeatureSpec {
|
||||||
|
return map[featuregate.Feature]featuregate.FeatureSpec{
|
||||||
|
ContextualLogging: {Default: contextualLoggingDefault, PreRelease: featuregate.Alpha},
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
// AddFeatureGates adds all feature gates used by this package.
|
||||||
|
func AddFeatureGates(mutableFeatureGate featuregate.MutableFeatureGate) error {
|
||||||
|
return mutableFeatureGate.Add(featureGates())
|
||||||
|
}
|
@ -168,6 +168,16 @@ func (writer KlogWriter) Write(data []byte) (n int, err error) {
|
|||||||
// InitLogs initializes logs the way we want for Kubernetes.
|
// InitLogs initializes logs the way we want for Kubernetes.
|
||||||
// It should be called after parsing flags. If called before that,
|
// It should be called after parsing flags. If called before that,
|
||||||
// it will use the default log settings.
|
// it will use the default log settings.
|
||||||
|
//
|
||||||
|
// InitLogs disables support for contextual logging in klog while
|
||||||
|
// that Kubernetes feature is not considered stable yet. Commands
|
||||||
|
// which want to support contextual logging can:
|
||||||
|
// - call klog.EnableContextualLogging after calling InitLogs,
|
||||||
|
// with a fixed `true` or depending on some command line flag or
|
||||||
|
// a feature gate check
|
||||||
|
// - set up a FeatureGate instance, the advanced logging configuration
|
||||||
|
// with Options and call Options.ValidateAndApply with the FeatureGate;
|
||||||
|
// k8s.io/component-base/logs/example/cmd demonstrates how to do that
|
||||||
func InitLogs() {
|
func InitLogs() {
|
||||||
log.SetOutput(KlogWriter{})
|
log.SetOutput(KlogWriter{})
|
||||||
log.SetFlags(0)
|
log.SetFlags(0)
|
||||||
@ -176,6 +186,10 @@ func InitLogs() {
|
|||||||
// Otherwise LoggingConfiguration.Apply will do this.
|
// Otherwise LoggingConfiguration.Apply will do this.
|
||||||
klog.StartFlushDaemon(logFlushFreq)
|
klog.StartFlushDaemon(logFlushFreq)
|
||||||
}
|
}
|
||||||
|
|
||||||
|
// This is the default in Kubernetes. Options.ValidateAndApply
|
||||||
|
// will override this with the result of a feature gate check.
|
||||||
|
klog.EnableContextualLogging(false)
|
||||||
}
|
}
|
||||||
|
|
||||||
// FlushLogs flushes logs immediately. This should be called at the end of
|
// FlushLogs flushes logs immediately. This should be called at the end of
|
||||||
|
@ -24,6 +24,7 @@ import (
|
|||||||
utilerrors "k8s.io/apimachinery/pkg/util/errors"
|
utilerrors "k8s.io/apimachinery/pkg/util/errors"
|
||||||
"k8s.io/component-base/config"
|
"k8s.io/component-base/config"
|
||||||
"k8s.io/component-base/config/v1alpha1"
|
"k8s.io/component-base/config/v1alpha1"
|
||||||
|
"k8s.io/component-base/featuregate"
|
||||||
"k8s.io/component-base/logs/registry"
|
"k8s.io/component-base/logs/registry"
|
||||||
"k8s.io/klog/v2"
|
"k8s.io/klog/v2"
|
||||||
)
|
)
|
||||||
@ -46,12 +47,15 @@ func NewOptions() *Options {
|
|||||||
// This should be invoked as early as possible because then the rest of the program
|
// This should be invoked as early as possible because then the rest of the program
|
||||||
// startup (including validation of other options) will already run with the final
|
// startup (including validation of other options) will already run with the final
|
||||||
// logging configuration.
|
// logging configuration.
|
||||||
func (o *Options) ValidateAndApply() error {
|
//
|
||||||
|
// The optional FeatureGate controls logging features. If nil, the default for
|
||||||
|
// these features is used.
|
||||||
|
func (o *Options) ValidateAndApply(featureGate featuregate.FeatureGate) error {
|
||||||
errs := o.validate()
|
errs := o.validate()
|
||||||
if len(errs) > 0 {
|
if len(errs) > 0 {
|
||||||
return utilerrors.NewAggregate(errs)
|
return utilerrors.NewAggregate(errs)
|
||||||
}
|
}
|
||||||
o.apply()
|
o.apply(featureGate)
|
||||||
return nil
|
return nil
|
||||||
}
|
}
|
||||||
|
|
||||||
@ -74,7 +78,12 @@ func (o *Options) AddFlags(fs *pflag.FlagSet) {
|
|||||||
}
|
}
|
||||||
|
|
||||||
// apply set klog logger from LogFormat type
|
// apply set klog logger from LogFormat type
|
||||||
func (o *Options) apply() {
|
func (o *Options) apply(featureGate featuregate.FeatureGate) {
|
||||||
|
contextualLoggingEnabled := contextualLoggingDefault
|
||||||
|
if featureGate != nil {
|
||||||
|
contextualLoggingEnabled = featureGate.Enabled(ContextualLogging)
|
||||||
|
}
|
||||||
|
|
||||||
// if log format not exists, use nil loggr
|
// if log format not exists, use nil loggr
|
||||||
factory, _ := registry.LogRegistry.Get(o.Config.Format)
|
factory, _ := registry.LogRegistry.Get(o.Config.Format)
|
||||||
if factory == nil {
|
if factory == nil {
|
||||||
@ -83,8 +92,9 @@ func (o *Options) apply() {
|
|||||||
// This logger will do its own verbosity checking, using the exact same
|
// This logger will do its own verbosity checking, using the exact same
|
||||||
// configuration as klog itself.
|
// configuration as klog itself.
|
||||||
log, flush := factory.Create(o.Config)
|
log, flush := factory.Create(o.Config)
|
||||||
// Therefore it can get called directly.
|
// Therefore it can get called directly. However, we only allow that
|
||||||
klog.SetLoggerWithOptions(log, klog.ContextualLogger(true), klog.FlushLogger(flush))
|
// when the feature is enabled.
|
||||||
|
klog.SetLoggerWithOptions(log, klog.ContextualLogger(contextualLoggingEnabled), klog.FlushLogger(flush))
|
||||||
}
|
}
|
||||||
if err := loggingFlags.Lookup("v").Value.Set(o.Config.Verbosity.String()); err != nil {
|
if err := loggingFlags.Lookup("v").Value.Set(o.Config.Verbosity.String()); err != nil {
|
||||||
panic(fmt.Errorf("internal error while setting klog verbosity: %v", err))
|
panic(fmt.Errorf("internal error while setting klog verbosity: %v", err))
|
||||||
@ -93,4 +103,5 @@ func (o *Options) apply() {
|
|||||||
panic(fmt.Errorf("internal error while setting klog vmodule: %v", err))
|
panic(fmt.Errorf("internal error while setting klog vmodule: %v", err))
|
||||||
}
|
}
|
||||||
klog.StartFlushDaemon(o.Config.FlushFrequency)
|
klog.StartFlushDaemon(o.Config.FlushFrequency)
|
||||||
|
klog.EnableContextualLogging(contextualLoggingEnabled)
|
||||||
}
|
}
|
||||||
|
@ -18,12 +18,16 @@ package logs
|
|||||||
|
|
||||||
import (
|
import (
|
||||||
"bytes"
|
"bytes"
|
||||||
|
"context"
|
||||||
"testing"
|
"testing"
|
||||||
|
|
||||||
|
"github.com/go-logr/logr"
|
||||||
"github.com/spf13/pflag"
|
"github.com/spf13/pflag"
|
||||||
"github.com/stretchr/testify/assert"
|
"github.com/stretchr/testify/assert"
|
||||||
|
"github.com/stretchr/testify/require"
|
||||||
|
|
||||||
"k8s.io/apimachinery/pkg/util/validation/field"
|
"k8s.io/apimachinery/pkg/util/validation/field"
|
||||||
|
"k8s.io/component-base/featuregate"
|
||||||
"k8s.io/klog/v2"
|
"k8s.io/klog/v2"
|
||||||
)
|
)
|
||||||
|
|
||||||
@ -89,7 +93,7 @@ func TestOptions(t *testing.T) {
|
|||||||
if !assert.Equal(t, tc.want, o) {
|
if !assert.Equal(t, tc.want, o) {
|
||||||
t.Errorf("Wrong Validate() result for %q. expect %v, got %v", tc.name, tc.want, o)
|
t.Errorf("Wrong Validate() result for %q. expect %v, got %v", tc.name, tc.want, o)
|
||||||
}
|
}
|
||||||
err := o.ValidateAndApply()
|
err := o.ValidateAndApply(nil /* We don't care about feature gates here. */)
|
||||||
defer klog.StopFlushDaemon()
|
defer klog.StopFlushDaemon()
|
||||||
|
|
||||||
if !assert.ElementsMatch(t, tc.errs.ToAggregate(), err) {
|
if !assert.ElementsMatch(t, tc.errs.ToAggregate(), err) {
|
||||||
@ -99,3 +103,42 @@ func TestOptions(t *testing.T) {
|
|||||||
})
|
})
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
|
func TestContextualLogging(t *testing.T) {
|
||||||
|
t.Run("enabled", func(t *testing.T) {
|
||||||
|
testContextualLogging(t, true)
|
||||||
|
})
|
||||||
|
|
||||||
|
t.Run("disabled", func(t *testing.T) {
|
||||||
|
testContextualLogging(t, false)
|
||||||
|
})
|
||||||
|
}
|
||||||
|
|
||||||
|
func testContextualLogging(t *testing.T, enabled bool) {
|
||||||
|
var err error
|
||||||
|
|
||||||
|
o := NewOptions()
|
||||||
|
featureGate := featuregate.NewFeatureGate()
|
||||||
|
AddFeatureGates(featureGate)
|
||||||
|
err = featureGate.SetFromMap(map[string]bool{string(ContextualLogging): enabled})
|
||||||
|
require.NoError(t, err)
|
||||||
|
err = o.ValidateAndApply(featureGate)
|
||||||
|
require.NoError(t, err)
|
||||||
|
defer klog.StopFlushDaemon()
|
||||||
|
defer klog.EnableContextualLogging(true)
|
||||||
|
|
||||||
|
ctx := context.Background()
|
||||||
|
logger := klog.NewKlogr().WithName("contextual")
|
||||||
|
ctx = logr.NewContext(ctx, logger)
|
||||||
|
if enabled {
|
||||||
|
assert.Equal(t, logger, klog.FromContext(ctx), "FromContext")
|
||||||
|
assert.NotEqual(t, ctx, klog.NewContext(ctx, logger), "NewContext")
|
||||||
|
assert.NotEqual(t, logger, klog.LoggerWithName(logger, "foo"), "LoggerWithName")
|
||||||
|
assert.NotEqual(t, logger, klog.LoggerWithValues(logger, "x", "y"), "LoggerWithValues")
|
||||||
|
} else {
|
||||||
|
assert.NotEqual(t, logger, klog.FromContext(ctx), "FromContext")
|
||||||
|
assert.Equal(t, ctx, klog.NewContext(ctx, logger), "NewContext")
|
||||||
|
assert.Equal(t, logger, klog.LoggerWithName(logger, "foo"), "LoggerWithName")
|
||||||
|
assert.Equal(t, logger, klog.LoggerWithValues(logger, "x", "y"), "LoggerWithValues")
|
||||||
|
}
|
||||||
|
}
|
||||||
|
Loading…
Reference in New Issue
Block a user