From d544435c732461c71563fee0e959226a6477e9cf Mon Sep 17 00:00:00 2001 From: Patrick Ohly Date: Wed, 9 Feb 2022 11:58:09 +0100 Subject: [PATCH] textlogger: add logger which emulates the traditional output In contrast to klogr, the formatting and printing is handled entirely by this logger without depending on klog.go. The intention is to use this in two ways: - for testing of SetLogger - as simpler text logger in Kubernetes for contextual logging --- test/output_test.go | 21 ++++++ textlogger/options.go | 104 +++++++++++++++++++++++++++ textlogger/textlogger.go | 148 +++++++++++++++++++++++++++++++++++++++ 3 files changed, 273 insertions(+) create mode 100644 textlogger/options.go create mode 100644 textlogger/textlogger.go diff --git a/test/output_test.go b/test/output_test.go index 8dad50b6e..5a43a1ced 100644 --- a/test/output_test.go +++ b/test/output_test.go @@ -23,6 +23,7 @@ import ( "github.com/go-logr/logr" "k8s.io/klog/v2/klogr" + "k8s.io/klog/v2/textlogger" ) func init() { @@ -34,6 +35,26 @@ func TestKlogOutput(t *testing.T) { Output(t, OutputConfig{}) } +// TestTextloggerOutput tests the textlogger, directly and as backend. +func TestTextloggerOutput(t *testing.T) { + newLogger := func(out io.Writer, v int, vmodule string) logr.Logger { + config := textlogger.NewConfig( + textlogger.Verbosity(v), + textlogger.Output(out), + ) + if err := config.VModule().Set(vmodule); err != nil { + panic(err) + } + return textlogger.NewLogger(config) + } + t.Run("direct", func(t *testing.T) { + Output(t, OutputConfig{NewLogger: newLogger, SupportsVModule: true}) + }) + t.Run("klog-backend", func(t *testing.T) { + Output(t, OutputConfig{NewLogger: newLogger, AsBackend: true}) + }) +} + // TestKlogrOutput tests klogr output via klog. func TestKlogrOutput(t *testing.T) { Output(t, OutputConfig{ diff --git a/textlogger/options.go b/textlogger/options.go new file mode 100644 index 000000000..0eee8727e --- /dev/null +++ b/textlogger/options.go @@ -0,0 +1,104 @@ +/* +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 textlogger + +import ( + "flag" + "io" + "os" + "strconv" + + "k8s.io/klog/v2/internal/verbosity" +) + +// Config influences logging in a text logger. To make this configurable via +// command line flags, instantiate this once per program and use AddFlags to +// bind command line flags to the instance before passing it to NewTestContext. +// +// Must be constructed with NewConfig. +type Config struct { + *verbosity.VState + co configOptions +} + +// ConfigOption implements functional parameters for NewConfig. +type ConfigOption func(co *configOptions) + +type configOptions struct { + verbosityFlagName string + vmoduleFlagName string + verbosityDefault int + output io.Writer +} + +// VerbosityFlagName overrides the default -v for the verbosity level. +func VerbosityFlagName(name string) ConfigOption { + return func(co *configOptions) { + + co.verbosityFlagName = name + } +} + +// VModulFlagName overrides the default -vmodule for the per-module +// verbosity levels. +func VModuleFlagName(name string) ConfigOption { + return func(co *configOptions) { + co.vmoduleFlagName = name + } +} + +// Verbosity overrides the default verbosity level of 0. +// See https://github.com/kubernetes/community/blob/9406b4352fe2d5810cb21cc3cb059ce5886de157/contributors/devel/sig-instrumentation/logging.md#logging-conventions +// for log level conventions in Kubernetes. +func Verbosity(level int) ConfigOption { + return func(co *configOptions) { + co.verbosityDefault = level + } +} + +// Output overrides stderr as the output stream. +func Output(output io.Writer) ConfigOption { + return func(co *configOptions) { + co.output = output + } +} + +// NewConfig returns a configuration with recommended defaults and optional +// modifications. Command line flags are not bound to any FlagSet yet. +func NewConfig(opts ...ConfigOption) *Config { + c := &Config{ + VState: verbosity.New(), + co: configOptions{ + verbosityFlagName: "v", + vmoduleFlagName: "vmodule", + verbosityDefault: 0, + output: os.Stderr, + }, + } + for _, opt := range opts { + opt(&c.co) + } + + c.V().Set(strconv.FormatInt(int64(c.co.verbosityDefault), 10)) + return c +} + +// AddFlags registers the command line flags that control the configuration. +func (c *Config) AddFlags(fs *flag.FlagSet) { + fs.Var(c.V(), c.co.verbosityFlagName, "number for the log level verbosity of the testing logger") + fs.Var(c.VModule(), c.co.vmoduleFlagName, "comma-separated list of pattern=N log level settings for files matching the patterns") +} diff --git a/textlogger/textlogger.go b/textlogger/textlogger.go new file mode 100644 index 000000000..6515be38e --- /dev/null +++ b/textlogger/textlogger.go @@ -0,0 +1,148 @@ +/* +Copyright 2019 The Kubernetes Authors. +Copyright 2020 Intel Coporation. + +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 textlogger contains an implementation of the logr interface +// which is producing the exact same output as klog. +package textlogger + +import ( + "runtime" + "strconv" + "strings" + "time" + + "github.com/go-logr/logr" + + "k8s.io/klog/v2/internal/buffer" + "k8s.io/klog/v2/internal/serialize" + "k8s.io/klog/v2/internal/severity" + "k8s.io/klog/v2/internal/verbosity" +) + +var ( + // TimeNow is used to retrieve the current time. May be changed for testing. + TimeNow = time.Now +) + +// NewLogger constructs a new logger. +func NewLogger(c *Config) logr.Logger { + return logr.New(&tlogger{ + prefix: "", + values: nil, + config: c, + bufferCache: &buffer.Buffers{}, + }) +} + +type tlogger struct { + callDepth int + prefix string + values []interface{} + config *Config + bufferCache *buffer.Buffers +} + +func copySlice(in []interface{}) []interface{} { + out := make([]interface{}, len(in)) + copy(out, in) + return out +} + +func (l *tlogger) Init(info logr.RuntimeInfo) { + l.callDepth = info.CallDepth +} + +func (l *tlogger) WithCallDepth(depth int) logr.LogSink { + newLogger := *l + newLogger.callDepth += depth + return &newLogger +} + +func (l *tlogger) Enabled(level int) bool { + return l.config.Enabled(verbosity.Level(level), 1) +} + +func (l *tlogger) Info(level int, msg string, kvList ...interface{}) { + l.print(nil, severity.InfoLog, msg, kvList) +} + +func (l *tlogger) Error(err error, msg string, kvList ...interface{}) { + l.print(err, severity.ErrorLog, msg, kvList) +} + +func (l *tlogger) print(err error, s severity.Severity, msg string, kvList []interface{}) { + // Only create a new buffer if we don't have one cached. + b := l.bufferCache.GetBuffer() + + // Determine caller. + // +1 for this frame, +1 for Info/Error. + _, file, line, ok := runtime.Caller(l.callDepth + 2) + if !ok { + file = "???" + line = 1 + } else { + if slash := strings.LastIndex(file, "/"); slash >= 0 { + path := file + file = path[slash+1:] + } + } + + // Format header. + now := TimeNow() + b.FormatHeader(s, file, line, now) + + // Inject WithName names into message. + if l.prefix != "" { + msg = l.prefix + ": " + msg + } + + // The message is always quoted, even if it contains line breaks. + // If developers want multi-line output, they should use a small, fixed + // message and put the multi-line output into a value. + b.WriteString(strconv.Quote(msg)) + if err != nil { + serialize.KVListFormat(&b.Buffer, "err", err) + } + trimmed := serialize.TrimDuplicates(l.values, kvList) + serialize.KVListFormat(&b.Buffer, trimmed[0]...) + serialize.KVListFormat(&b.Buffer, trimmed[1]...) + if b.Len() == 0 || b.Bytes()[b.Len()-1] != '\n' { + b.WriteByte('\n') + } + l.config.co.output.Write(b.Bytes()) +} + +// WithName returns a new logr.Logger with the specified name appended. klogr +// uses '/' characters to separate name elements. Callers should not pass '/' +// in the provided name string, but this library does not actually enforce that. +func (l *tlogger) WithName(name string) logr.LogSink { + new := *l + if len(l.prefix) > 0 { + new.prefix = l.prefix + "/" + } + new.prefix += name + return &new +} + +func (l *tlogger) WithValues(kvList ...interface{}) logr.LogSink { + new := *l + new.values = serialize.WithValues(l.values, kvList) + return &new +} + +var _ logr.LogSink = &tlogger{} +var _ logr.CallDepthLogSink = &tlogger{}