Skip to content

Commit

Permalink
contextual logging
Browse files Browse the repository at this point in the history
This moves the global logger into a separate file together with the functions
that implement contextual logging.
  • Loading branch information
pohly committed Mar 10, 2022
1 parent d888550 commit df761fd
Show file tree
Hide file tree
Showing 4 changed files with 381 additions and 72 deletions.
197 changes: 197 additions & 0 deletions contextual.go
@@ -0,0 +1,197 @@
/*
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 klog

import (
"context"

"github.com/go-logr/logr"
)

// This file provides the implementation of
// https://github.com/kubernetes/enhancements/tree/master/keps/sig-instrumentation/1602-structured-logging
//
// SetLogger and ClearLogger were originally added to klog.go and got moved
// here. Contextual logging adds a way to retrieve a Logger for direct logging
// without the logging calls in klog.go.
//
// The global variables are expected to be modified only during sequential
// parts of a program (init, serial tests) and therefore are not protected by
// mutex locking.

var (
// contextualLoggingEnabled controls whether contextual logging is
// active. Disabling it may have some small performance benefit.
contextualLoggingEnabled = true

// globalLogger is the global Logger chosen by users of klog, nil if
// none is available.
globalLogger *Logger

// contextualLogger defines whether globalLogger may get called
// directly.
contextualLogger bool

// klogLogger is used as fallback for logging through the normal klog code
// when no Logger is set.
klogLogger logr.Logger = logr.New(&klogger{})
)

// SetLogger sets a Logger implementation that will be used as backing
// implementation of the traditional klog log calls. klog will do its own
// verbosity checks before calling logger.V().Info. logger.Error is always
// called, regardless of the klog verbosity settings.
//
// If set, all log lines will be suppressed from the regular Output, and
// redirected to the logr implementation.
// Use as:
// ...
// klog.SetLogger(zapr.NewLogger(zapLog))
//
// To remove a backing logr implemention, use ClearLogger. Setting an
// empty logger with SetLogger(logr.Logger{}) does not work.
//
// Modifying the logger is not thread-safe and should be done while no other
// goroutines invoke log calls, usually during program initialization.
func SetLogger(logger logr.Logger) {
globalLogger = &logger
contextualLogger = false
}

// SetContextualLogger does the same as SetLogger, but in addition the
// logger may also get called directly by code that retrieves it
// with FromContext, TODO or Background. The logger therefore must
// implements its own verbosity checking.
func SetContextualLogger(logger logr.Logger) {
globalLogger = &logger
contextualLogger = true
}

// ClearLogger removes a backing Logger implementation if one was set earlier
// with SetLogger.
//
// Modifying the logger is not thread-safe and should be done while no other
// goroutines invoke log calls, usually during program initialization.
func ClearLogger() {
globalLogger = nil
}

// EnableContextualLogging controls whether contextual logging is enabled.
// By default it is enabled. When disabled, FromContext avoids looking up
// the logger in the context and always returns the global logger.
// LoggerWithValues, LoggerWithName, and NewContext become no-ops
// and return their input logger respectively context. This may be useful
// to avoid the additional overhead for contextual logging.
//
// This must be called during initialization before goroutines are started.
//
// Experimental
//
// Notice: This function is EXPERIMENTAL and may be changed or removed in a
// later release.
func EnableContextualLogging(enabled bool) {
contextualLoggingEnabled = enabled
}

// FromContext retrieves a logger set by the caller or, if not set,
// falls back to the program's global logger (a Logger instance or klog
// itself).
//
// Experimental
//
// Notice: This function is EXPERIMENTAL and may be changed or removed in a
// later release.
func FromContext(ctx context.Context) Logger {
if contextualLoggingEnabled {
if logger, err := logr.FromContext(ctx); err == nil {
return logger
}
}

return Background()
}

// TODO can be used as a last resort by code that has no means of
// receiving a logger from its caller. FromContext or an explicit logger
// parameter should be used instead.
//
// Experimental
//
// Notice: This function is EXPERIMENTAL and may be changed or removed in a
// later release.
func TODO() Logger {
return Background()
}

// Background retrieves the fallback logger. It should not be called before
// that logger was initialized by the program and not by code that should
// better receive a logger via its parameters. TODO can be used as a temporary
// solution for such code.
//
// Experimental
//
// Notice: This function is EXPERIMENTAL and may be changed or removed in a
// later release.
func Background() Logger {
if globalLogger != nil && contextualLogger {
return *globalLogger
}

return klogLogger
}

// LoggerWithValues returns logger.WithValues(...kv) when
// contextual logging is enabled, otherwise the logger.
//
// Experimental
//
// Notice: This function is EXPERIMENTAL and may be changed or removed in a
// later release.
func LoggerWithValues(logger Logger, kv ...interface{}) Logger {
if contextualLoggingEnabled {
return logger.WithValues(kv...)
}
return logger
}

// LoggerWithName returns logger.WithName(name) when contextual logging is
// enabled, otherwise the logger.
//
// Experimental
//
// Notice: This function is EXPERIMENTAL and may be changed or removed in a
// later release.
func LoggerWithName(logger Logger, name string) Logger {
if contextualLoggingEnabled {
return logger.WithName(name)
}
return logger
}

// NewContext returns logr.NewContext(ctx, logger) when
// contextual logging is enabled, otherwise ctx.
//
// Experimental
//
// Notice: This function is EXPERIMENTAL and may be changed or removed in a
// later release.
func NewContext(ctx context.Context, logger Logger) context.Context {
if contextualLoggingEnabled {
return logr.NewContext(ctx, logger)
}
return ctx
}
55 changes: 53 additions & 2 deletions examples/output_test/output_test.go
Expand Up @@ -85,7 +85,7 @@ func TestKlogrOutput(t *testing.T) {
})
}

// TestKlogrStackText tests klogr -> klog -> text logger.
// TestKlogrStackText tests klogr.klogr -> klog -> text logger.
func TestKlogrStackText(t *testing.T) {
newLogger := func(out io.Writer, v int, vmodule string) logr.Logger {
// Backend: text output.
Expand All @@ -104,7 +104,7 @@ func TestKlogrStackText(t *testing.T) {
test.Output(t, test.OutputConfig{NewLogger: newLogger, SupportsVModule: true})
}

// TestKlogrStackKlogr tests klogr -> klog -> zapr.
// TestKlogrStackKlogr tests klogr.klogr -> klog -> zapr.
//
// This exposes whether verbosity is passed through correctly
// (https://github.com/kubernetes/klog/issues/294) because klogr logging
Expand Down Expand Up @@ -136,6 +136,57 @@ func TestKlogrStackZapr(t *testing.T) {
test.Output(t, test.OutputConfig{NewLogger: newLogger, ExpectedOutputMapping: mapping})
}

// TestKlogrInternalStackText tests klog.klogr (the simplified version used for contextual logging) -> klog -> text logger.
func TestKlogrInternalStackText(t *testing.T) {
newLogger := func(out io.Writer, v int, vmodule string) logr.Logger {
// Backend: text output.
config := textlogger.NewConfig(
textlogger.Verbosity(v),
textlogger.Output(out),
)
if err := config.VModule().Set(vmodule); err != nil {
panic(err)
}
klog.SetLogger(textlogger.NewLogger(config))

// Frontend: internal klogr.
return klog.NewKlogr()
}
test.Output(t, test.OutputConfig{NewLogger: newLogger, SupportsVModule: true})
}

// TestKlogrInternalStackKlogr tests klog.klogr (the simplified version used for contextual logging) -> klog -> zapr.
//
// This exposes whether verbosity is passed through correctly
// (https://github.com/kubernetes/klog/issues/294) because klogr logging
// records that.
func TestKlogrInternalStackZapr(t *testing.T) {
mapping := test.ZaprOutputMappingIndirect()

// klogr doesn't warn about invalid KVs and just inserts
// "(MISSING)".
for key, value := range map[string]string{
`I output.go:<LINE>] "odd arguments" akey="avalue" akey2="(MISSING)"
`: `{"caller":"test/output.go:<LINE>","msg":"odd arguments","v":0,"akey":"avalue","akey2":"(MISSING)"}
`,

`I output.go:<LINE>] "both odd" basekey1="basevar1" basekey2="(MISSING)" akey="avalue" akey2="(MISSING)"
`: `{"caller":"test/output.go:<LINE>","msg":"both odd","v":0,"basekey1":"basevar1","basekey2":"(MISSING)","akey":"avalue","akey2":"(MISSING)"}
`,
} {
mapping[key] = value
}

newLogger := func(out io.Writer, v int, vmodule string) logr.Logger {
// Backend: zapr as configured in k8s.io/component-base/logs/json.
klog.SetLogger(newZaprLogger(out, v))

// Frontend: internal klogr.
return klog.NewKlogr()
}
test.Output(t, test.OutputConfig{NewLogger: newLogger, ExpectedOutputMapping: mapping})
}

func newZaprLogger(out io.Writer, v int) logr.Logger {
encoderConfig := &zapcore.EncoderConfig{
MessageKey: "msg",
Expand Down

0 comments on commit df761fd

Please sign in to comment.