From 40c4015d5f365ffe86f9c811464dc689c77b6914 Mon Sep 17 00:00:00 2001 From: Patrick Ohly Date: Fri, 15 Sep 2023 13:13:49 +0200 Subject: [PATCH 1/2] component-base/logs: add slog support Integration of a slog-based package into a Kubernetes application is completely transparent when that package uses the global slog default logger because component-base will set that. When the package wants to be passed a logger instance, then one can be constructed with slogr.NewSlogHandler. Integration of a Kubernetes package into an application which uses a slog Logger is a bit more work when configuring logging. The main binary must call klog.SetLogger and needs logr/slogr to convert a slog.Handler to a logr.Logger. --- .../component-base/logs/api/v1/options.go | 1 + .../logs/api/v1/options_no_slog.go | 24 +++++ .../logs/api/v1/options_slog.go | 37 ++++++++ .../component-base/logs/example/README.md | 3 + .../logs/example/k8s2slog/k8s2slog.go | 89 +++++++++++++++++++ .../logs/example/slog2k8s/slog2k8s.go | 50 +++++++++++ 6 files changed, 204 insertions(+) create mode 100644 staging/src/k8s.io/component-base/logs/api/v1/options_no_slog.go create mode 100644 staging/src/k8s.io/component-base/logs/api/v1/options_slog.go create mode 100644 staging/src/k8s.io/component-base/logs/example/k8s2slog/k8s2slog.go create mode 100644 staging/src/k8s.io/component-base/logs/example/slog2k8s/slog2k8s.go diff --git a/staging/src/k8s.io/component-base/logs/api/v1/options.go b/staging/src/k8s.io/component-base/logs/api/v1/options.go index 4abcc1de812..754443bf6fd 100644 --- a/staging/src/k8s.io/component-base/logs/api/v1/options.go +++ b/staging/src/k8s.io/component-base/logs/api/v1/options.go @@ -282,6 +282,7 @@ func apply(c *LoggingConfiguration, options *LoggingOptions, featureGate feature if err := loggingFlags.Lookup("vmodule").Value.Set(VModuleConfigurationPflag(&c.VModule).String()); err != nil { return fmt.Errorf("internal error while setting klog vmodule: %v", err) } + setSlogDefaultLogger() klog.StartFlushDaemon(c.FlushFrequency.Duration.Duration) klog.EnableContextualLogging(p.ContextualLoggingEnabled) return nil diff --git a/staging/src/k8s.io/component-base/logs/api/v1/options_no_slog.go b/staging/src/k8s.io/component-base/logs/api/v1/options_no_slog.go new file mode 100644 index 00000000000..816948e0a6f --- /dev/null +++ b/staging/src/k8s.io/component-base/logs/api/v1/options_no_slog.go @@ -0,0 +1,24 @@ +//go:build !go1.21 +// +build !go1.21 + +/* +Copyright 2023 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 v1 + +func setSlogDefaultLogger() { + // Do nothing when build with Go < 1.21. +} diff --git a/staging/src/k8s.io/component-base/logs/api/v1/options_slog.go b/staging/src/k8s.io/component-base/logs/api/v1/options_slog.go new file mode 100644 index 00000000000..31765e644db --- /dev/null +++ b/staging/src/k8s.io/component-base/logs/api/v1/options_slog.go @@ -0,0 +1,37 @@ +//go:build go1.21 +// +build go1.21 + +/* +Copyright 2023 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 v1 + +import ( + "log/slog" + + "github.com/go-logr/logr" + "k8s.io/klog/v2" +) + +// setSlogDefaultLogger sets the global slog default logger to the same default +// that klog currently uses. +func setSlogDefaultLogger() { + // klog.Background() always returns a valid logr.Logger, regardless of + // how logging was configured. We just need to turn it into a + // slog.Handler. SetDefault then needs a slog.Logger. + handler := logr.ToSlogHandler(klog.Background()) + slog.SetDefault(slog.New(handler)) +} diff --git a/staging/src/k8s.io/component-base/logs/example/README.md b/staging/src/k8s.io/component-base/logs/example/README.md index a2a3a295115..aafc34d5036 100644 --- a/staging/src/k8s.io/component-base/logs/example/README.md +++ b/staging/src/k8s.io/component-base/logs/example/README.md @@ -5,6 +5,9 @@ component-base/logs and what effect the different command line options have. Like most Kubernetes components, `cmd` uses Cobra and pflags. `stdlib` uses just plain Go libraries. `test` contains a unit test with per-test output. +`slog2k8s` shows how an application using `log/slog` from Go 1.21 can include +packages from Kubernetes. `k8s2slog` is the other direction. + Below we can see examples of how some features work. ## Default diff --git a/staging/src/k8s.io/component-base/logs/example/k8s2slog/k8s2slog.go b/staging/src/k8s.io/component-base/logs/example/k8s2slog/k8s2slog.go new file mode 100644 index 00000000000..c39ef9fe7a6 --- /dev/null +++ b/staging/src/k8s.io/component-base/logs/example/k8s2slog/k8s2slog.go @@ -0,0 +1,89 @@ +//go:build go1.21 +// +build go1.21 + +/* +Copyright 2018 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 main + +import ( + "context" + "fmt" + "log/slog" + "os" + "strings" + + "github.com/spf13/cobra" + + metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" + "k8s.io/apimachinery/pkg/util/runtime" + "k8s.io/component-base/cli" + "k8s.io/component-base/featuregate" + "k8s.io/component-base/logs" + logsapi "k8s.io/component-base/logs/api/v1" + "k8s.io/klog/v2" + + _ "k8s.io/component-base/logs/json/register" +) + +var featureGate = featuregate.NewFeatureGate() + +func main() { + runtime.Must(logsapi.AddFeatureGates(featureGate)) + command := NewLoggerCommand() + code := cli.Run(command) + os.Exit(code) +} + +func NewLoggerCommand() *cobra.Command { + c := logsapi.NewLoggingConfiguration() + cmd := &cobra.Command{ + Run: func(cmd *cobra.Command, args []string) { + // This configures the global logger in klog *and* slog, if compiled + // with Go >= 1.21. + logs.InitLogs() + if err := logsapi.ValidateAndApply(c, featureGate); err != nil { + fmt.Fprintf(os.Stderr, "%v\n", err) + os.Exit(1) + } + if len(args) > 0 { + fmt.Fprintf(os.Stderr, "Unexpected additional command line arguments:\n %s\n", strings.Join(args, "\n ")) + os.Exit(1) + } + + // Produce some output. Special types used by Kubernetes work. + podRef := klog.KObj(&metav1.ObjectMeta{Name: "some-pod", Namespace: "some-namespace"}) + podRefs := klog.KObjSlice([]interface{}{ + &metav1.ObjectMeta{Name: "some-pod", Namespace: "some-namespace"}, + nil, + &metav1.ObjectMeta{Name: "other-pod"}, + }) + slog.Info("slog.Info", "pod", podRef, "pods", podRefs) + klog.InfoS("klog.InfoS", "pod", podRef, "pods", podRefs) + klog.Background().Info("klog.Background+logr.Logger.Info") + klog.FromContext(context.Background()).Info("klog.FromContext+logr.Logger.Info") + slogLogger := slog.Default() + slogLogger.Info("slog.Default+slog.Logger.Info") + }, + } + if err := logsapi.AddFeatureGates(featureGate); err != nil { + // Shouldn't happen. + panic(err) + } + featureGate.AddFlag(cmd.Flags()) + logsapi.AddFlags(c, cmd.Flags()) + return cmd +} diff --git a/staging/src/k8s.io/component-base/logs/example/slog2k8s/slog2k8s.go b/staging/src/k8s.io/component-base/logs/example/slog2k8s/slog2k8s.go new file mode 100644 index 00000000000..440141e0900 --- /dev/null +++ b/staging/src/k8s.io/component-base/logs/example/slog2k8s/slog2k8s.go @@ -0,0 +1,50 @@ +//go:build go1.21 +// +build go1.21 + +/* +Copyright 2023 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. +*/ + +// slog2k8s demonstrates how an application using log/slog for logging +// can include Kubernetes packages. +package main + +import ( + "context" + "log/slog" + "os" + + "k8s.io/klog/v2" +) + +func main() { + options := slog.HandlerOptions{AddSource: true} + textHandler := slog.NewTextHandler(os.Stderr, &options) + textLogger := slog.New(textHandler) + + // Use text output as default logger. + slog.SetDefault(textLogger) + + // This also needs to be done through klog to ensure that all code + // using klog uses the text handler. klog.Background/TODO/FromContext + // will return a thin wrapper around the textHandler, so all that klog + // still does is manage the global default and retrieval from contexts. + klog.SetSlogLogger(textLogger) + + textLogger.Info("slog.Logger.Info") + klog.InfoS("klog.InfoS") + klog.Background().Info("klog.Background+logr.Logger.Info") + klog.FromContext(context.Background()).Info("klog.FromContext+logr.Logger.Info") +} From 4d5264fb0be58efc456cf625a3ee63a5edee04b8 Mon Sep 17 00:00:00 2001 From: Patrick Ohly Date: Fri, 15 Sep 2023 13:13:49 +0200 Subject: [PATCH 2/2] logging benchmark: support slog MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Replacing zapr with slog as JSON implementation can be benchmarked by replacing "false" with "true" and rerunning. However, slog is slower: Encoding/error-value/JSON-36 171k ± 3% 148k ± 5% -13.64% (p=0.008 n=5+5) Encoding/error/JSON-36 207k ± 9% 149k ± 4% -27.87% (p=0.008 n=5+5) Encoding/kind-worker-kubelet/JSON-36 348k ± 2% 334k ± 1% -4.13% (p=0.008 n=5+5) Encoding/kube-apiserver/JSON-36 210k ± 2% 186k ± 1% -11.53% (p=0.008 n=5+5) Encoding/kube-controller-manager/JSON-36 291k ± 1% 249k ± 2% -14.26% (p=0.008 n=5+5) Encoding/kube-scheduler/JSON-36 262k ± 4% 223k ± 2% -14.91% (p=0.008 n=5+5) Encoding/simple/JSON-36 161k ± 4% 132k ± 2% -17.60% (p=0.008 n=5+5) Encoding/split/JSON-36 159k ± 4% 132k ± 1% -17.23% (p=0.008 n=5+5) Encoding/v3/kind-worker-kubelet/JSON-36 255k ± 1% 256k ± 1% ~ (p=0.222 n=5+5) Encoding/v3/kube-apiserver/JSON-36 131k ± 4% 105k ± 4% -20.07% (p=0.008 n=5+5) Encoding/v3/kube-controller-manager/JSON-36 285k ± 2% 250k ± 2% -12.13% (p=0.008 n=5+5) Encoding/v3/kube-scheduler/JSON-36 216k ± 3% 196k ± 4% -9.63% (p=0.008 n=5+5) --- .../logs/benchmark/benchmark_test.go | 40 +++++++++++++++++++ 1 file changed, 40 insertions(+) diff --git a/test/integration/logs/benchmark/benchmark_test.go b/test/integration/logs/benchmark/benchmark_test.go index abc92e55531..30a906c82ed 100644 --- a/test/integration/logs/benchmark/benchmark_test.go +++ b/test/integration/logs/benchmark/benchmark_test.go @@ -20,6 +20,7 @@ import ( "errors" "io" "io/fs" + "log/slog" "os" "path/filepath" "regexp" @@ -29,6 +30,8 @@ import ( "testing" "time" + "github.com/go-logr/logr" + "go.uber.org/zap/zapcore" "k8s.io/component-base/featuregate" logsapi "k8s.io/component-base/logs/api/v1" _ "k8s.io/component-base/logs/json/register" @@ -93,6 +96,43 @@ func BenchmarkEncoding(b *testing.B) { b.Fatalf("Unexpected error configuring logging: %v", err) } logger := klog.Background() + + // Edit and run with this if branch enabled to use slog instead of zapr for JSON. + if format == "json" && false { + var level slog.LevelVar + level.Set(slog.Level(-3)) // hack + logger = logr.FromSlogHandler(slog.NewJSONHandler(output, &slog.HandlerOptions{ + AddSource: true, + Level: &level, + ReplaceAttr: func(groups []string, a slog.Attr) slog.Attr { + switch a.Key { + case slog.TimeKey: + // Could be user-supplied "time". + if a.Value.Kind() == slog.KindTime { + return slog.Float64("ts", float64(a.Value.Time().UnixMicro())/1000) + } + case slog.LevelKey: + level := a.Value.Any().(slog.Level) + if level >= slog.LevelError { + // No verbosity on errors. + return slog.Attr{} + } + if level >= 0 { + return slog.Int("v", 0) + } + return slog.Int("v", int(-level)) + case slog.SourceKey: + caller := zapcore.EntryCaller{ + Defined: true, + File: a.Value.String(), + } + return slog.String("caller", caller.TrimmedPath()) + } + return a + }, + })) + } + b.ResetTimer() start := time.Now() total := int64(0)