From 8881b718229192392a7e9db71dd11349f2108346 Mon Sep 17 00:00:00 2001 From: Patrick Ohly Date: Tue, 20 Dec 2022 15:50:39 +0100 Subject: [PATCH 1/3] k8s.io/component-base/logs/json: fix package name Having the sub-package using the same name as the parent package makes no sense. This seems to be a cut-and-paste error. --- staging/src/k8s.io/component-base/logs/json/json.go | 2 +- .../src/k8s.io/component-base/logs/json/json_benchmark_test.go | 2 +- staging/src/k8s.io/component-base/logs/json/json_test.go | 2 +- staging/src/k8s.io/component-base/logs/json/klog_test.go | 2 +- 4 files changed, 4 insertions(+), 4 deletions(-) diff --git a/staging/src/k8s.io/component-base/logs/json/json.go b/staging/src/k8s.io/component-base/logs/json/json.go index 1ccd0f3de64..9f422eb525c 100644 --- a/staging/src/k8s.io/component-base/logs/json/json.go +++ b/staging/src/k8s.io/component-base/logs/json/json.go @@ -14,7 +14,7 @@ See the License for the specific language governing permissions and limitations under the License. */ -package logs +package json import ( "io" diff --git a/staging/src/k8s.io/component-base/logs/json/json_benchmark_test.go b/staging/src/k8s.io/component-base/logs/json/json_benchmark_test.go index 76b9fad3429..67e16b83b0d 100644 --- a/staging/src/k8s.io/component-base/logs/json/json_benchmark_test.go +++ b/staging/src/k8s.io/component-base/logs/json/json_benchmark_test.go @@ -14,7 +14,7 @@ See the License for the specific language governing permissions and limitations under the License. */ -package logs +package json import ( "fmt" diff --git a/staging/src/k8s.io/component-base/logs/json/json_test.go b/staging/src/k8s.io/component-base/logs/json/json_test.go index e0492505759..88bba09ef7e 100644 --- a/staging/src/k8s.io/component-base/logs/json/json_test.go +++ b/staging/src/k8s.io/component-base/logs/json/json_test.go @@ -14,7 +14,7 @@ See the License for the specific language governing permissions and limitations under the License. */ -package logs +package json import ( "bytes" diff --git a/staging/src/k8s.io/component-base/logs/json/klog_test.go b/staging/src/k8s.io/component-base/logs/json/klog_test.go index a9a54fc19c4..1439ee3f9e3 100644 --- a/staging/src/k8s.io/component-base/logs/json/klog_test.go +++ b/staging/src/k8s.io/component-base/logs/json/klog_test.go @@ -14,7 +14,7 @@ See the License for the specific language governing permissions and limitations under the License. */ -package logs +package json import ( "bytes" From 9b86f457e93bc629434dd0a861e40539a5c7da37 Mon Sep 17 00:00:00 2001 From: Patrick Ohly Date: Tue, 20 Dec 2022 16:05:46 +0100 Subject: [PATCH 2/3] k8s.io/component-base/logs: support changing verbosity of JSON output The GlogSetter method is used by three components to change verbosity at runtime through HTTP APIs. This used to work only for text output with klog calls, but not for text output through the klog logger or for JSON output. Now loggers can also provide a callback for changing their verbosity at runtime. Implementing that implies that the Create factory method has to be extended, which is an API break for the Go package, but not an API break for the configuration file and command line flags, which is what matters for the "api/v1" component API. --- .../src/k8s.io/apiextensions-apiserver/go.sum | 1 + staging/src/k8s.io/apiserver/go.sum | 1 + staging/src/k8s.io/cloud-provider/go.sum | 1 + .../component-base/logs/api/v1/options.go | 10 +- .../component-base/logs/api/v1/registry.go | 23 +++- .../setverbositylevel/setverbositylevel.go | 34 ++++++ .../k8s.io/component-base/logs/json/json.go | 49 ++++++-- .../src/k8s.io/component-base/logs/logs.go | 19 ++- .../k8s.io/component-base/logs/logs_test.go | 114 ++++++++++++++++++ staging/src/k8s.io/controller-manager/go.sum | 1 + staging/src/k8s.io/kube-aggregator/go.sum | 1 + staging/src/k8s.io/sample-apiserver/go.sum | 1 + .../logs/benchmark/benchmark_test.go | 16 ++- vendor/modules.txt | 1 + 14 files changed, 249 insertions(+), 23 deletions(-) create mode 100644 staging/src/k8s.io/component-base/logs/internal/setverbositylevel/setverbositylevel.go create mode 100644 staging/src/k8s.io/component-base/logs/logs_test.go diff --git a/staging/src/k8s.io/apiextensions-apiserver/go.sum b/staging/src/k8s.io/apiextensions-apiserver/go.sum index ab4cbe153ef..d4597d85a01 100644 --- a/staging/src/k8s.io/apiextensions-apiserver/go.sum +++ b/staging/src/k8s.io/apiextensions-apiserver/go.sum @@ -153,6 +153,7 @@ github.com/go-logr/logr v1.2.3 h1:2DntVwHkVopvECVRSlL5PSo9eG+cAkDCuckLubN+rq0= github.com/go-logr/logr v1.2.3/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A= github.com/go-logr/stdr v1.2.2 h1:hSWxHoqTgW2S2qGc0LTAI563KZ5YKYRhT3MFKZMbjag= github.com/go-logr/stdr v1.2.2/go.mod h1:mMo/vtBO5dYbehREoey6XUKy/eSumjCCveDpRre4VKE= +github.com/go-logr/zapr v1.2.3 h1:a9vnzlIBPQBBkeaR9IuMUfmVOrQlkoC4YfPoFkX3T7A= github.com/go-openapi/jsonpointer v0.19.6 h1:eCs3fxoIi3Wh6vtgmLTOjdhSpiqphQ+DaPn38N2ZdrE= github.com/go-openapi/jsonpointer v0.19.6/go.mod h1:osyAmYz/mB/C3I+WsTTSgw1ONzaLJoLCyoi6/zppojs= github.com/go-openapi/jsonreference v0.20.1 h1:FBLnyygC4/IZZr893oiomc9XaghoveYTrLC1F86HID8= diff --git a/staging/src/k8s.io/apiserver/go.sum b/staging/src/k8s.io/apiserver/go.sum index fbcd31c2f2d..bfb2b8ec83c 100644 --- a/staging/src/k8s.io/apiserver/go.sum +++ b/staging/src/k8s.io/apiserver/go.sum @@ -166,6 +166,7 @@ github.com/go-logr/logr v1.2.3 h1:2DntVwHkVopvECVRSlL5PSo9eG+cAkDCuckLubN+rq0= github.com/go-logr/logr v1.2.3/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A= github.com/go-logr/stdr v1.2.2 h1:hSWxHoqTgW2S2qGc0LTAI563KZ5YKYRhT3MFKZMbjag= github.com/go-logr/stdr v1.2.2/go.mod h1:mMo/vtBO5dYbehREoey6XUKy/eSumjCCveDpRre4VKE= +github.com/go-logr/zapr v1.2.3 h1:a9vnzlIBPQBBkeaR9IuMUfmVOrQlkoC4YfPoFkX3T7A= github.com/go-openapi/jsonpointer v0.19.6 h1:eCs3fxoIi3Wh6vtgmLTOjdhSpiqphQ+DaPn38N2ZdrE= github.com/go-openapi/jsonpointer v0.19.6/go.mod h1:osyAmYz/mB/C3I+WsTTSgw1ONzaLJoLCyoi6/zppojs= github.com/go-openapi/jsonreference v0.20.1 h1:FBLnyygC4/IZZr893oiomc9XaghoveYTrLC1F86HID8= diff --git a/staging/src/k8s.io/cloud-provider/go.sum b/staging/src/k8s.io/cloud-provider/go.sum index bf20162030d..dfc6bc9f193 100644 --- a/staging/src/k8s.io/cloud-provider/go.sum +++ b/staging/src/k8s.io/cloud-provider/go.sum @@ -124,6 +124,7 @@ github.com/go-logr/logr v1.2.3 h1:2DntVwHkVopvECVRSlL5PSo9eG+cAkDCuckLubN+rq0= github.com/go-logr/logr v1.2.3/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A= github.com/go-logr/stdr v1.2.2 h1:hSWxHoqTgW2S2qGc0LTAI563KZ5YKYRhT3MFKZMbjag= github.com/go-logr/stdr v1.2.2/go.mod h1:mMo/vtBO5dYbehREoey6XUKy/eSumjCCveDpRre4VKE= +github.com/go-logr/zapr v1.2.3 h1:a9vnzlIBPQBBkeaR9IuMUfmVOrQlkoC4YfPoFkX3T7A= github.com/go-openapi/jsonpointer v0.19.6 h1:eCs3fxoIi3Wh6vtgmLTOjdhSpiqphQ+DaPn38N2ZdrE= github.com/go-openapi/jsonpointer v0.19.6/go.mod h1:osyAmYz/mB/C3I+WsTTSgw1ONzaLJoLCyoi6/zppojs= github.com/go-openapi/jsonreference v0.20.1 h1:FBLnyygC4/IZZr893oiomc9XaghoveYTrLC1F86HID8= 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 6270b2eb96f..41acb975d94 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 @@ -31,6 +31,7 @@ import ( "k8s.io/apimachinery/pkg/util/validation/field" cliflag "k8s.io/component-base/cli/flag" "k8s.io/component-base/featuregate" + "k8s.io/component-base/logs/internal/setverbositylevel" "k8s.io/component-base/logs/klogflags" ) @@ -167,8 +168,13 @@ func apply(c *LoggingConfiguration, featureGate featuregate.FeatureGate) error { if format.factory == nil { klog.ClearLogger() } else { - log, flush := format.factory.Create(*c) - klog.SetLoggerWithOptions(log, klog.ContextualLogger(contextualLoggingEnabled), klog.FlushLogger(flush)) + log, control := format.factory.Create(*c) + if control.SetVerbosityLevel != nil { + setverbositylevel.Mutex.Lock() + defer setverbositylevel.Mutex.Unlock() + setverbositylevel.Callbacks = append(setverbositylevel.Callbacks, control.SetVerbosityLevel) + } + klog.SetLoggerWithOptions(log, klog.ContextualLogger(contextualLoggingEnabled), klog.FlushLogger(control.Flush)) } if err := loggingFlags.Lookup("v").Value.Set(VerbosityLevelPflag(&c.Verbosity).String()); err != nil { return fmt.Errorf("internal error while setting klog verbosity: %v", err) diff --git a/staging/src/k8s.io/component-base/logs/api/v1/registry.go b/staging/src/k8s.io/component-base/logs/api/v1/registry.go index 78bc8f8853f..0f333c0bddf 100644 --- a/staging/src/k8s.io/component-base/logs/api/v1/registry.go +++ b/staging/src/k8s.io/component-base/logs/api/v1/registry.go @@ -39,14 +39,29 @@ type logFormat struct { feature featuregate.Feature } +// +k8s:deepcopy-gen=false + +// RuntimeControl provides operations that aren't available through the normal +// Logger or LogSink API. +type RuntimeControl struct { + // Flush ensures that all in-memory data is written. + // May be nil. + Flush func() + + // SetVerbosityLevel changes the level for all Logger instances + // derived from the initial one. May be nil. + // + // The parameter is intentionally a plain uint32 instead of + // VerbosityLevel to enable implementations that don't need to import + // the API (helps avoid circular dependencies). + SetVerbosityLevel func(v uint32) error +} + // LogFormatFactory provides support for a certain additional, // non-default log format. type LogFormatFactory interface { // Create returns a logger with the requested configuration. - // Returning a flush function for the logger is optional. - // If provided, the caller must ensure that it is called - // periodically (if desired) and at program exit. - Create(c LoggingConfiguration) (log logr.Logger, flush func()) + Create(c LoggingConfiguration) (logr.Logger, RuntimeControl) } // RegisterLogFormat registers support for a new logging format. This must be called diff --git a/staging/src/k8s.io/component-base/logs/internal/setverbositylevel/setverbositylevel.go b/staging/src/k8s.io/component-base/logs/internal/setverbositylevel/setverbositylevel.go new file mode 100644 index 00000000000..c643bae9bc3 --- /dev/null +++ b/staging/src/k8s.io/component-base/logs/internal/setverbositylevel/setverbositylevel.go @@ -0,0 +1,34 @@ +/* +Copyright 2022 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 setverbositylevel stores callbacks that will be invoked by logs.GlogLevel. +// +// This is a separate package to avoid a dependency from +// k8s.io/component-base/logs (uses the callbacks) to +// k8s.io/component-base/logs/api/v1 (adds them). Not all users of the logs +// package also use the API. +package setverbositylevel + +import ( + "sync" +) + +var ( + // Mutex controls access to the callbacks. + Mutex sync.Mutex + + Callbacks []func(v uint32) error +) diff --git a/staging/src/k8s.io/component-base/logs/json/json.go b/staging/src/k8s.io/component-base/logs/json/json.go index 9f422eb525c..423c88e654f 100644 --- a/staging/src/k8s.io/component-base/logs/json/json.go +++ b/staging/src/k8s.io/component-base/logs/json/json.go @@ -19,6 +19,7 @@ package json import ( "io" "os" + "sync/atomic" "time" "github.com/go-logr/logr" @@ -35,12 +36,32 @@ var ( timeNow = time.Now ) -// NewJSONLogger creates a new json logr.Logger and its associated -// flush function. The separate error stream is optional and may be nil. -// The encoder config is also optional. -func NewJSONLogger(v logsapi.VerbosityLevel, infoStream, errorStream zapcore.WriteSyncer, encoderConfig *zapcore.EncoderConfig) (logr.Logger, func()) { +type runtime struct { + v uint32 +} + +func (r *runtime) ZapV() zapcore.Level { // zap levels are inverted: everything with a verbosity >= threshold gets logged. - zapV := -zapcore.Level(v) + return -zapcore.Level(atomic.LoadUint32(&r.v)) +} + +// Enabled implements the zapcore.LevelEnabler interface. +func (r *runtime) Enabled(level zapcore.Level) bool { + return level >= r.ZapV() +} + +func (r *runtime) SetVerbosityLevel(v uint32) error { + atomic.StoreUint32(&r.v, v) + return nil +} + +var _ zapcore.LevelEnabler = &runtime{} + +// NewJSONLogger creates a new json logr.Logger and its associated +// control interface. The separate error stream is optional and may be nil. +// The encoder config is also optional. +func NewJSONLogger(v logsapi.VerbosityLevel, infoStream, errorStream zapcore.WriteSyncer, encoderConfig *zapcore.EncoderConfig) (logr.Logger, logsapi.RuntimeControl) { + r := &runtime{v: uint32(v)} if encoderConfig == nil { encoderConfig = &zapcore.EncoderConfig{ @@ -57,13 +78,13 @@ func NewJSONLogger(v logsapi.VerbosityLevel, infoStream, errorStream zapcore.Wri encoder := zapcore.NewJSONEncoder(*encoderConfig) var core zapcore.Core if errorStream == nil { - core = zapcore.NewCore(encoder, infoStream, zapV) + core = zapcore.NewCore(encoder, infoStream, r) } else { highPriority := zap.LevelEnablerFunc(func(lvl zapcore.Level) bool { - return lvl >= zapcore.ErrorLevel && lvl >= zapV + return lvl >= zapcore.ErrorLevel && r.Enabled(lvl) }) lowPriority := zap.LevelEnablerFunc(func(lvl zapcore.Level) bool { - return lvl < zapcore.ErrorLevel && lvl >= zapV + return lvl < zapcore.ErrorLevel && r.Enabled(lvl) }) core = zapcore.NewTee( zapcore.NewCore(encoder, errorStream, highPriority), @@ -71,9 +92,13 @@ func NewJSONLogger(v logsapi.VerbosityLevel, infoStream, errorStream zapcore.Wri ) } l := zap.New(core, zap.WithCaller(true)) - return zapr.NewLoggerWithOptions(l, zapr.LogInfoLevel("v"), zapr.ErrorKey("err")), func() { - l.Sync() - } + return zapr.NewLoggerWithOptions(l, zapr.LogInfoLevel("v"), zapr.ErrorKey("err")), + logsapi.RuntimeControl{ + SetVerbosityLevel: r.SetVerbosityLevel, + Flush: func() { + _ = l.Sync() + }, + } } func epochMillisTimeEncoder(_ time.Time, enc zapcore.PrimitiveArrayEncoder) { @@ -91,7 +116,7 @@ func (f Factory) Feature() featuregate.Feature { return logsapi.LoggingBetaOptions } -func (f Factory) Create(c logsapi.LoggingConfiguration) (logr.Logger, func()) { +func (f Factory) Create(c logsapi.LoggingConfiguration) (logr.Logger, logsapi.RuntimeControl) { // We intentionally avoid all os.File.Sync calls. Output is unbuffered, // therefore we don't need to flush, and calling the underlying fsync // would just slow down writing. diff --git a/staging/src/k8s.io/component-base/logs/logs.go b/staging/src/k8s.io/component-base/logs/logs.go index 886c154e4bf..7fda0f9117f 100644 --- a/staging/src/k8s.io/component-base/logs/logs.go +++ b/staging/src/k8s.io/component-base/logs/logs.go @@ -23,10 +23,12 @@ import ( "flag" "fmt" "log" + "strconv" "time" "github.com/spf13/pflag" logsapi "k8s.io/component-base/logs/api/v1" + "k8s.io/component-base/logs/internal/setverbositylevel" "k8s.io/component-base/logs/klogflags" "k8s.io/klog/v2" ) @@ -182,11 +184,26 @@ func NewLogger(prefix string) *log.Logger { return log.New(KlogWriter{}, prefix, 0) } -// GlogSetter is a setter to set glog level. +// GlogSetter modifies the verbosity threshold for the entire program. +// Some components have HTTP-based APIs for invoking this at runtime. func GlogSetter(val string) (string, error) { + v, err := strconv.ParseUint(val, 10, 32) + if err != nil { + return "", err + } + var level klog.Level if err := level.Set(val); err != nil { return "", fmt.Errorf("failed set klog.logging.verbosity %s: %v", val, err) } + + setverbositylevel.Mutex.Lock() + defer setverbositylevel.Mutex.Unlock() + for _, cb := range setverbositylevel.Callbacks { + if err := cb(uint32(v)); err != nil { + return "", err + } + } + return fmt.Sprintf("successfully set klog.logging.verbosity to %s", val), nil } diff --git a/staging/src/k8s.io/component-base/logs/logs_test.go b/staging/src/k8s.io/component-base/logs/logs_test.go new file mode 100644 index 00000000000..01f543f12ca --- /dev/null +++ b/staging/src/k8s.io/component-base/logs/logs_test.go @@ -0,0 +1,114 @@ +/* +Copyright 2022 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_test + +import ( + "os" + "path" + "testing" + + "k8s.io/component-base/logs" + logsapi "k8s.io/component-base/logs/api/v1" + _ "k8s.io/component-base/logs/json/register" + "k8s.io/klog/v2" +) + +func TestGlogSetter(t *testing.T) { + testcases := map[string]struct { + init func(t *testing.T) + // write must write at verbosity level 1. + write func() + }{ + "klog": { + init: func(t *testing.T) {}, + write: func() { + klog.V(1).Info("hello") + }, + }, + "json": { + init: func(t *testing.T) { + c := logsapi.NewLoggingConfiguration() + c.Format = "json" + if err := logsapi.ValidateAndApply(c, nil /* feature gates */); err != nil { + t.Fatalf("Unexpected error enabling json output: %v", err) + } + }, + write: func() { + klog.Background().V(1).Info("hello") + }, + }, + "text": { + init: func(t *testing.T) { + c := logsapi.NewLoggingConfiguration() + c.Format = "text" + if err := logsapi.ValidateAndApply(c, nil /* feature gates */); err != nil { + t.Fatalf("Unexpected error enabling text output: %v", err) + } + }, + write: func() { + klog.Background().V(1).Info("hello") + }, + }, + } + + for name, tc := range testcases { + t.Run(name, func(t *testing.T) { + state := klog.CaptureState() + t.Cleanup(state.Restore) + tmpdir := t.TempDir() + tmpfile := path.Join(tmpdir, "stderr.log") + oldStderr := os.Stderr + defer func() { + os.Stderr = oldStderr + }() + newStderr, err := os.Create(tmpfile) + if err != nil { + t.Fatalf("Unexpected error creating temp file: %v", err) + } + os.Stderr = newStderr + + tc.init(t) + + // First write with default verbosity level of 0 -> no output. + tc.write() + klog.Flush() + out, err := os.ReadFile(tmpfile) + if err != nil { + t.Fatalf("Unexpected error reading temp file: %v", err) + } + if len(out) > 0 { + t.Fatalf("Info message should have been discarded, got instead:\n%s", string(out)) + } + + // Increase verbosity at runtime. + if _, err := logs.GlogSetter("1"); err != nil { + t.Fatalf("Unexpected error setting verbosity level: %v", err) + } + + // Now write again -> output. + tc.write() + klog.Flush() + out, err = os.ReadFile(tmpfile) + if err != nil { + t.Fatalf("Unexpected error reading temp file: %v", err) + } + if len(out) == 0 { + t.Fatal("Info message should have been written, got empty file instead.") + } + }) + } +} diff --git a/staging/src/k8s.io/controller-manager/go.sum b/staging/src/k8s.io/controller-manager/go.sum index f05ca808758..6bc308876b9 100644 --- a/staging/src/k8s.io/controller-manager/go.sum +++ b/staging/src/k8s.io/controller-manager/go.sum @@ -120,6 +120,7 @@ github.com/go-logr/logr v1.2.3 h1:2DntVwHkVopvECVRSlL5PSo9eG+cAkDCuckLubN+rq0= github.com/go-logr/logr v1.2.3/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A= github.com/go-logr/stdr v1.2.2 h1:hSWxHoqTgW2S2qGc0LTAI563KZ5YKYRhT3MFKZMbjag= github.com/go-logr/stdr v1.2.2/go.mod h1:mMo/vtBO5dYbehREoey6XUKy/eSumjCCveDpRre4VKE= +github.com/go-logr/zapr v1.2.3 h1:a9vnzlIBPQBBkeaR9IuMUfmVOrQlkoC4YfPoFkX3T7A= github.com/go-openapi/jsonpointer v0.19.6 h1:eCs3fxoIi3Wh6vtgmLTOjdhSpiqphQ+DaPn38N2ZdrE= github.com/go-openapi/jsonpointer v0.19.6/go.mod h1:osyAmYz/mB/C3I+WsTTSgw1ONzaLJoLCyoi6/zppojs= github.com/go-openapi/jsonreference v0.20.1 h1:FBLnyygC4/IZZr893oiomc9XaghoveYTrLC1F86HID8= diff --git a/staging/src/k8s.io/kube-aggregator/go.sum b/staging/src/k8s.io/kube-aggregator/go.sum index 1a009269098..9e4c7620b54 100644 --- a/staging/src/k8s.io/kube-aggregator/go.sum +++ b/staging/src/k8s.io/kube-aggregator/go.sum @@ -122,6 +122,7 @@ github.com/go-logr/logr v1.2.3 h1:2DntVwHkVopvECVRSlL5PSo9eG+cAkDCuckLubN+rq0= github.com/go-logr/logr v1.2.3/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A= github.com/go-logr/stdr v1.2.2 h1:hSWxHoqTgW2S2qGc0LTAI563KZ5YKYRhT3MFKZMbjag= github.com/go-logr/stdr v1.2.2/go.mod h1:mMo/vtBO5dYbehREoey6XUKy/eSumjCCveDpRre4VKE= +github.com/go-logr/zapr v1.2.3 h1:a9vnzlIBPQBBkeaR9IuMUfmVOrQlkoC4YfPoFkX3T7A= github.com/go-openapi/jsonpointer v0.19.6 h1:eCs3fxoIi3Wh6vtgmLTOjdhSpiqphQ+DaPn38N2ZdrE= github.com/go-openapi/jsonpointer v0.19.6/go.mod h1:osyAmYz/mB/C3I+WsTTSgw1ONzaLJoLCyoi6/zppojs= github.com/go-openapi/jsonreference v0.20.1 h1:FBLnyygC4/IZZr893oiomc9XaghoveYTrLC1F86HID8= diff --git a/staging/src/k8s.io/sample-apiserver/go.sum b/staging/src/k8s.io/sample-apiserver/go.sum index 408ee0a4d59..3bcd37d7b1c 100644 --- a/staging/src/k8s.io/sample-apiserver/go.sum +++ b/staging/src/k8s.io/sample-apiserver/go.sum @@ -122,6 +122,7 @@ github.com/go-logr/logr v1.2.3 h1:2DntVwHkVopvECVRSlL5PSo9eG+cAkDCuckLubN+rq0= github.com/go-logr/logr v1.2.3/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A= github.com/go-logr/stdr v1.2.2 h1:hSWxHoqTgW2S2qGc0LTAI563KZ5YKYRhT3MFKZMbjag= github.com/go-logr/stdr v1.2.2/go.mod h1:mMo/vtBO5dYbehREoey6XUKy/eSumjCCveDpRre4VKE= +github.com/go-logr/zapr v1.2.3 h1:a9vnzlIBPQBBkeaR9IuMUfmVOrQlkoC4YfPoFkX3T7A= github.com/go-openapi/jsonpointer v0.19.6 h1:eCs3fxoIi3Wh6vtgmLTOjdhSpiqphQ+DaPn38N2ZdrE= github.com/go-openapi/jsonpointer v0.19.6/go.mod h1:osyAmYz/mB/C3I+WsTTSgw1ONzaLJoLCyoi6/zppojs= github.com/go-openapi/jsonreference v0.20.1 h1:FBLnyygC4/IZZr893oiomc9XaghoveYTrLC1F86HID8= diff --git a/test/integration/logs/benchmark/benchmark_test.go b/test/integration/logs/benchmark/benchmark_test.go index 91bc8348997..31c5f60605c 100644 --- a/test/integration/logs/benchmark/benchmark_test.go +++ b/test/integration/logs/benchmark/benchmark_test.go @@ -194,14 +194,18 @@ func benchmarkOutputFormats(b *testing.B, config loadGeneratorConfig, discard bo } b.Run("single-stream", func(b *testing.B) { if discard { - logger, flush = logsjson.NewJSONLogger(c.Verbosity, logsjson.AddNopSync(&output), nil, nil) + l, control := logsjson.NewJSONLogger(c.Verbosity, logsjson.AddNopSync(&output), nil, nil) + logger = l + flush = control.Flush } else { stderr := os.Stderr os.Stderr = out1 defer func() { os.Stderr = stderr }() - logger, flush = logsjson.Factory{}.Create(*c) + l, control := logsjson.Factory{}.Create(*c) + logger = l + flush = control.Flush } klog.SetLogger(logger) defer klog.ClearLogger() @@ -210,7 +214,9 @@ func benchmarkOutputFormats(b *testing.B, config loadGeneratorConfig, discard bo b.Run("split-stream", func(b *testing.B) { if discard { - logger, flush = logsjson.NewJSONLogger(c.Verbosity, logsjson.AddNopSync(&output), logsjson.AddNopSync(&output), nil) + l, control := logsjson.NewJSONLogger(c.Verbosity, logsjson.AddNopSync(&output), logsjson.AddNopSync(&output), nil) + logger = l + flush = control.Flush } else { stdout, stderr := os.Stdout, os.Stderr os.Stdout, os.Stderr = out1, out2 @@ -219,7 +225,9 @@ func benchmarkOutputFormats(b *testing.B, config loadGeneratorConfig, discard bo }() c := logsapi.NewLoggingConfiguration() c.Options.JSON.SplitStream = true - logger, flush = logsjson.Factory{}.Create(*c) + l, control := logsjson.Factory{}.Create(*c) + logger = l + flush = control.Flush } klog.SetLogger(logger) defer klog.ClearLogger() diff --git a/vendor/modules.txt b/vendor/modules.txt index b8f88661475..393efd9ce32 100644 --- a/vendor/modules.txt +++ b/vendor/modules.txt @@ -2000,6 +2000,7 @@ k8s.io/component-base/featuregate k8s.io/component-base/featuregate/testing k8s.io/component-base/logs k8s.io/component-base/logs/api/v1 +k8s.io/component-base/logs/internal/setverbositylevel k8s.io/component-base/logs/json k8s.io/component-base/logs/json/register k8s.io/component-base/logs/klogflags From a41424d4c82f1f069756baadc43c2ce09331ebad Mon Sep 17 00:00:00 2001 From: Patrick Ohly Date: Wed, 21 Dec 2022 16:41:59 +0100 Subject: [PATCH 3/3] k8s.io/component-base/logs: allow overriding os.Stdout and os.Stderr This is useful for tests which need to discard or capture the output. --- .../component-base/logs/api/v1/options.go | 39 ++++++++++++-- .../component-base/logs/api/v1/registry.go | 2 +- .../k8s.io/component-base/logs/json/json.go | 7 ++- .../logs/benchmark/benchmark_test.go | 52 ++++++------------- 4 files changed, 55 insertions(+), 45 deletions(-) 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 41acb975d94..9990e31fff2 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 @@ -19,7 +19,9 @@ package v1 import ( "flag" "fmt" + "io" "math" + "os" "strings" "time" @@ -63,18 +65,41 @@ func NewLoggingConfiguration() *LoggingConfiguration { // The optional FeatureGate controls logging features. If nil, the default for // these features is used. func ValidateAndApply(c *LoggingConfiguration, featureGate featuregate.FeatureGate) error { - return ValidateAndApplyAsField(c, featureGate, nil) + return validateAndApply(c, nil, featureGate, nil) +} + +// ValidateAndApplyWithOptions is a variant of ValidateAndApply which accepts +// additional options beyond those that can be configured through the API. This +// is meant for testing. +func ValidateAndApplyWithOptions(c *LoggingConfiguration, options *LoggingOptions, featureGate featuregate.FeatureGate) error { + return validateAndApply(c, options, featureGate, nil) +} + +// +k8s:deepcopy-gen=false + +// LoggingOptions can be used with ValidateAndApplyWithOptions to override +// certain global defaults. +type LoggingOptions struct { + // ErrorStream can be used to override the os.Stderr default. + ErrorStream io.Writer + + // InfoStream can be used to override the os.Stdout default. + InfoStream io.Writer } // ValidateAndApplyAsField is a variant of ValidateAndApply that should be used // when the LoggingConfiguration is embedded in some larger configuration // structure. func ValidateAndApplyAsField(c *LoggingConfiguration, featureGate featuregate.FeatureGate, fldPath *field.Path) error { + return validateAndApply(c, nil, featureGate, fldPath) +} + +func validateAndApply(c *LoggingConfiguration, options *LoggingOptions, featureGate featuregate.FeatureGate, fldPath *field.Path) error { errs := Validate(c, featureGate, fldPath) if len(errs) > 0 { return errs.ToAggregate() } - return apply(c, featureGate) + return apply(c, options, featureGate) } // Validate can be used to check for invalid settings without applying them. @@ -157,7 +182,7 @@ func featureEnabled(featureGate featuregate.FeatureGate, feature featuregate.Fea return enabled } -func apply(c *LoggingConfiguration, featureGate featuregate.FeatureGate) error { +func apply(c *LoggingConfiguration, options *LoggingOptions, featureGate featuregate.FeatureGate) error { contextualLoggingEnabled := contextualLoggingDefault if featureGate != nil { contextualLoggingEnabled = featureGate.Enabled(ContextualLogging) @@ -168,7 +193,13 @@ func apply(c *LoggingConfiguration, featureGate featuregate.FeatureGate) error { if format.factory == nil { klog.ClearLogger() } else { - log, control := format.factory.Create(*c) + if options == nil { + options = &LoggingOptions{ + ErrorStream: os.Stderr, + InfoStream: os.Stdout, + } + } + log, control := format.factory.Create(*c, *options) if control.SetVerbosityLevel != nil { setverbositylevel.Mutex.Lock() defer setverbositylevel.Mutex.Unlock() diff --git a/staging/src/k8s.io/component-base/logs/api/v1/registry.go b/staging/src/k8s.io/component-base/logs/api/v1/registry.go index 0f333c0bddf..f8fc1f2cae1 100644 --- a/staging/src/k8s.io/component-base/logs/api/v1/registry.go +++ b/staging/src/k8s.io/component-base/logs/api/v1/registry.go @@ -61,7 +61,7 @@ type RuntimeControl struct { // non-default log format. type LogFormatFactory interface { // Create returns a logger with the requested configuration. - Create(c LoggingConfiguration) (logr.Logger, RuntimeControl) + Create(c LoggingConfiguration, o LoggingOptions) (logr.Logger, RuntimeControl) } // RegisterLogFormat registers support for a new logging format. This must be called diff --git a/staging/src/k8s.io/component-base/logs/json/json.go b/staging/src/k8s.io/component-base/logs/json/json.go index 423c88e654f..20723687e98 100644 --- a/staging/src/k8s.io/component-base/logs/json/json.go +++ b/staging/src/k8s.io/component-base/logs/json/json.go @@ -18,7 +18,6 @@ package json import ( "io" - "os" "sync/atomic" "time" @@ -116,7 +115,7 @@ func (f Factory) Feature() featuregate.Feature { return logsapi.LoggingBetaOptions } -func (f Factory) Create(c logsapi.LoggingConfiguration) (logr.Logger, logsapi.RuntimeControl) { +func (f Factory) Create(c logsapi.LoggingConfiguration, o logsapi.LoggingOptions) (logr.Logger, logsapi.RuntimeControl) { // We intentionally avoid all os.File.Sync calls. Output is unbuffered, // therefore we don't need to flush, and calling the underlying fsync // would just slow down writing. @@ -125,9 +124,9 @@ func (f Factory) Create(c logsapi.LoggingConfiguration) (logr.Logger, logsapi.Ru // written to the output stream before the process terminates, but // doesn't need to worry about data not being written because of a // system crash or powerloss. - stderr := zapcore.Lock(AddNopSync(os.Stderr)) + stderr := zapcore.Lock(AddNopSync(o.ErrorStream)) if c.Options.JSON.SplitStream { - stdout := zapcore.Lock(AddNopSync(os.Stdout)) + stdout := zapcore.Lock(AddNopSync(o.InfoStream)) size := c.Options.JSON.InfoBufferSize.Value() if size > 0 { // Prevent integer overflow. diff --git a/test/integration/logs/benchmark/benchmark_test.go b/test/integration/logs/benchmark/benchmark_test.go index 31c5f60605c..6c071ce38cd 100644 --- a/test/integration/logs/benchmark/benchmark_test.go +++ b/test/integration/logs/benchmark/benchmark_test.go @@ -32,7 +32,6 @@ import ( "testing" "time" - "github.com/go-logr/logr" logsapi "k8s.io/component-base/logs/api/v1" logsjson "k8s.io/component-base/logs/json" "k8s.io/klog/v2" @@ -175,9 +174,6 @@ func benchmarkOutputFormats(b *testing.B, config loadGeneratorConfig, discard bo generateOutput(b, config, nil, out) }) b.Run("JSON", func(b *testing.B) { - c := logsapi.NewLoggingConfiguration() - var logger logr.Logger - var flush func() var out1, out2 *os.File if !discard { var err error @@ -192,46 +188,30 @@ func benchmarkOutputFormats(b *testing.B, config loadGeneratorConfig, discard bo } defer out2.Close() } + o := logsapi.LoggingOptions{} + if discard { + o.ErrorStream = io.Discard + o.InfoStream = io.Discard + } else { + o.ErrorStream = out1 + o.InfoStream = out1 + } + b.Run("single-stream", func(b *testing.B) { - if discard { - l, control := logsjson.NewJSONLogger(c.Verbosity, logsjson.AddNopSync(&output), nil, nil) - logger = l - flush = control.Flush - } else { - stderr := os.Stderr - os.Stderr = out1 - defer func() { - os.Stderr = stderr - }() - l, control := logsjson.Factory{}.Create(*c) - logger = l - flush = control.Flush - } + c := logsapi.NewLoggingConfiguration() + logger, control := logsjson.Factory{}.Create(*c, o) klog.SetLogger(logger) defer klog.ClearLogger() - generateOutput(b, config, flush, out1) + generateOutput(b, config, control.Flush, out1) }) b.Run("split-stream", func(b *testing.B) { - if discard { - l, control := logsjson.NewJSONLogger(c.Verbosity, logsjson.AddNopSync(&output), logsjson.AddNopSync(&output), nil) - logger = l - flush = control.Flush - } else { - stdout, stderr := os.Stdout, os.Stderr - os.Stdout, os.Stderr = out1, out2 - defer func() { - os.Stdout, os.Stderr = stdout, stderr - }() - c := logsapi.NewLoggingConfiguration() - c.Options.JSON.SplitStream = true - l, control := logsjson.Factory{}.Create(*c) - logger = l - flush = control.Flush - } + c := logsapi.NewLoggingConfiguration() + c.Options.JSON.SplitStream = true + logger, control := logsjson.Factory{}.Create(*c, o) klog.SetLogger(logger) defer klog.ClearLogger() - generateOutput(b, config, flush, out1, out2) + generateOutput(b, config, control.Flush, out1, out2) }) }) }