ktesting

Documentation

Overview

Package testinglogger contains an implementation of the logr interface which is logging through a function like testing.TB.Log function. Therefore it can be used in standard Go tests and Gingko test suites to ensure that output is associated with the currently running test.

In addition, the log data is captured in a buffer and can be used by the test to verify that the code under test is logging as expected. To get access to that data, cast the LogSink into the Underlier type and retrieve it:

logger := ktesting.NewLogger(...)
if testingLogger, ok := logger.GetSink().(ktesting.Underlier); ok {
    t := testingLogger.GetUnderlying()
    buffer := testingLogger.GetBuffer()
    text := buffer.String()
    log := buffer.Data()

Serialization of the structured log parameters is done in the same way as for klog.InfoS.

Experimental

Notice: This package is EXPERIMENTAL and may be changed or removed in a later release.

Index

• Constants
• Variables
• func NewLogger(t TL, c *Config) logr.Logger
• func NewTestContext(tl TL) (logr.Logger, context.Context)
• type Buffer
• type BufferTL
  • func (n *BufferTL) Helper()
  • func (n *BufferTL) Log(args ...interface{})
• type Config
  • func NewConfig(opts ...ConfigOption) *Config
  • func (c *Config) AddFlags(fs *flag.FlagSet)
  • func (c *Config) VModule() flag.Value
  • func (c *Config) Verbosity() flag.Value
• type ConfigOption
  • func AnyToString(anyToString func(value interface{}) string) ConfigOption
  • func BufferLogs(enabled bool) ConfigOption
  • func VModuleFlagName(name string) ConfigOption
  • func Verbosity(level int) ConfigOption
  • func VerbosityFlagName(name string) ConfigOption
• type Log
  • func (l Log) DeepCopy() Log
• type LogEntry
• type LogType
• type NopTL
  • func (n NopTL) Helper()
  • func (n NopTL) Log(args ...interface{})
• type TL
• type Underlier

Examples

• Config.Verbosity
• NewLogger
• Underlier

Constants

const (
	// LogError is the special value used for Error log entries.
	//
	// Experimental
	//
	// Notice: This value is EXPERIMENTAL and may be changed or removed in
	// a later release.
	LogError = LogType("ERROR")

	// LogInfo is the special value used for Info log entries.
	//
	// Experimental
	//
	// Notice: This value is EXPERIMENTAL and may be changed or removed in
	// a later release.
	LogInfo = LogType("INFO")
)

Variables

var DefaultConfig = NewConfig()

DefaultConfig is the global default logging configuration for a unit test. It is used by NewTestContext and k8s.io/klogr/testing/init.

Experimental

Notice: This variable is EXPERIMENTAL and may be changed or removed in a later release.

Functions

func NewLogger

func NewLogger(t TL, c *Config) logr.Logger

NewLogger constructs a new logger for the given test interface.

Beware that testing.T does not support logging after the test that it was created for has completed. If a test leaks goroutines and those goroutines log something after test completion, that output will be printed via the global klog logger with `<test name> leaked goroutine` as prefix.

Verbosity can be modified at any time through the Config.V and Config.VModule API.

Experimental

Notice: This type is EXPERIMENTAL and may be changed or removed in a later release.

Example

var buffer ktesting.BufferTL
logger := ktesting.NewLogger(&buffer, ktesting.NewConfig())

logger.Error(errors.New("failure"), "I failed", "what", "something", "data", struct{ field int }{field: 1})
logger.V(5).Info("Logged at level 5.")
logger.V(6).Info("Not logged at level 6.")

testingLogger, ok := logger.GetSink().(ktesting.Underlier)
if !ok {
	panic("Should have had a ktesting LogSink!?")
}
fmt.Printf(">> %s <<\n", testingLogger.GetBuffer().String())       // Should be empty.
fmt.Print(headerRe.ReplaceAllString(buffer.String(), "${1}...] ")) // Should not be empty.

Output:

>>  <<
E...] I failed err="failure" what="something" data={field:1}
I...] Logged at level 5.

func NewTestContext

func NewTestContext(tl TL) (logr.Logger, context.Context)

NewTestContext returns a logger and context for use in a unit test case or benchmark. The tl parameter can be a testing.T or testing.B pointer that will receive all log output. Importing k8s.io/klogr/testing/init will add command line flags that modify the configuration of that log output.

Experimental

Notice: This function is EXPERIMENTAL and may be changed or removed in a later release.

Types

type Buffer

type Buffer interface {
	// String returns the log entries in a format that is similar to the
	// klog text output.
	String() string

	// Data returns the log entries as structs.
	Data() Log
}

Buffer stores log entries as formatted text and structured data. It is safe to use this concurrently.

Experimental

Notice: This interface is EXPERIMENTAL and may be changed or removed in a later release.

type BufferTL

type BufferTL struct {
	strings.Builder
}

BufferTL implements TL with an in-memory buffer.

Experimental

Notice: This type is EXPERIMENTAL and may be changed or removed in a later release.

func (*BufferTL) Helper

func (n *BufferTL) Helper()

func (*BufferTL) Log

func (n *BufferTL) Log(args ...interface{})

type Config

type Config struct {
	// contains filtered or unexported fields
}

Config influences logging in a test 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.

Experimental

Notice: This type is EXPERIMENTAL and may be changed or removed in a later release.

func NewConfig

func NewConfig(opts ...ConfigOption) *Config

NewConfig returns a configuration with recommended defaults and optional modifications. Command line flags are not bound to any FlagSet yet.

Experimental

Notice: This function is EXPERIMENTAL and may be changed or removed in a later release.

func (*Config) AddFlags

func (c *Config) AddFlags(fs *flag.FlagSet)

AddFlags registers the command line flags that control the configuration.

Experimental

Notice: This function is EXPERIMENTAL and may be changed or removed in a later release.

func (*Config) VModule

func (c *Config) VModule() flag.Value

VModule returns a value instance that can be used to query (via String) or modify (via Set) the vmodule settings. This is thread-safe and can be done at runtime.

func (*Config) Verbosity

func (c *Config) Verbosity() flag.Value

Verbosity returns a value instance that can be used to query (via String) or modify (via Set) the verbosity threshold. This is thread-safe and can be done at runtime.

Example

var buffer ktesting.BufferTL
config := ktesting.NewConfig(ktesting.Verbosity(1))
logger := ktesting.NewLogger(&buffer, config)

logger.Info("initial verbosity", "v", config.Verbosity().String())
logger.V(2).Info("now you don't see me")
if err := config.Verbosity().Set("2"); err != nil {
	logger.Error(err, "setting verbosity to 2")
}
logger.V(2).Info("now you see me")
if err := config.Verbosity().Set("1"); err != nil {
	logger.Error(err, "setting verbosity to 1")
}
logger.V(2).Info("now I'm gone again")

fmt.Print(headerRe.ReplaceAllString(buffer.String(), "${1}...] "))

Output:

I...] initial verbosity v="1"
I...] now you see me

type ConfigOption

type ConfigOption func(co *configOptions)

ConfigOption implements functional parameters for NewConfig.

Experimental

Notice: This type is EXPERIMENTAL and may be changed or removed in a later release.

func AnyToString

func AnyToString(anyToString func(value interface{}) string) ConfigOption

AnyToString overrides the default formatter for values that are not supported directly by klog. The default is `fmt.Sprintf("%+v")`. The formatter must not panic.

Experimental

Notice: This function is EXPERIMENTAL and may be changed or removed in a later release.

func BufferLogs

func BufferLogs(enabled bool) ConfigOption

BufferLogs controls whether log entries are captured in memory in addition to being printed. Off by default. Unit tests that want to verify that log entries are emitted as expected can turn this on and then retrieve the captured log through the Underlier LogSink interface.

Experimental

Notice: This function is EXPERIMENTAL and may be changed or removed in a later release.

func VModuleFlagName

func VModuleFlagName(name string) ConfigOption

VModulFlagName overrides the default -testing.vmodule for the per-module verbosity levels.

Experimental

Notice: This function is EXPERIMENTAL and may be changed or removed in a later release.

func Verbosity

func Verbosity(level int) ConfigOption

Verbosity overrides the default verbosity level of 5. That default is higher than in klog itself because it enables logging entries for "the steps leading up to errors and warnings" and "troubleshooting" (see https://github.com/kubernetes/community/blob/9406b4352fe2d5810cb21cc3cb059ce5886de157/contributors/devel/sig-instrumentation/logging.md#logging-conventions), which is useful when debugging a failed test. `go test` only shows the log output for failed tests. To see all output, use `go test -v`.

Experimental

Notice: This function is EXPERIMENTAL and may be changed or removed in a later release.

func VerbosityFlagName

func VerbosityFlagName(name string) ConfigOption

VerbosityFlagName overrides the default -testing.v for the verbosity level.

Experimental

Notice: This function is EXPERIMENTAL and may be changed or removed in a later release.

type Log

type Log []LogEntry

Log contains log entries in the order in which they were generated.

Experimental

Notice: This type is EXPERIMENTAL and may be changed or removed in a later release.

func (Log) DeepCopy

func (l Log) DeepCopy() Log

DeepCopy returns a copy of the log. The error instance and key/value pairs remain shared.

Experimental

Notice: This function is EXPERIMENTAL and may be changed or removed in a later release.

type LogEntry

type LogEntry struct {
	// Timestamp stores the time when the log entry was created.
	Timestamp time.Time

	// Type is either LogInfo or LogError.
	Type LogType

	// Prefix contains the WithName strings concatenated with a slash.
	Prefix string

	// Message is the fixed log message string.
	Message string

	// Verbosity is always 0 for LogError.
	Verbosity int

	// Err is always nil for LogInfo. It may or may not be
	// nil for LogError.
	Err error

	// WithKVList are the concatenated key/value pairs from WithValues
	// calls. It's guaranteed to have an even number of entries because
	// the logger ensures that when WithValues is called.
	WithKVList []interface{}

	// ParameterKVList are the key/value pairs passed into the call,
	// without any validation.
	ParameterKVList []interface{}
}

LogEntry represents all information captured for a log entry.

Experimental

Notice: This type is EXPERIMENTAL and may be changed or removed in a later release.

type LogType

type LogType string

LogType determines whether a log entry was created with an Error or Info call.

Experimental

Notice: This type is EXPERIMENTAL and may be changed or removed in a later release.

type NopTL

type NopTL struct{}

NopTL implements TL with empty stubs. It can be used when only capturing output in memory is relevant.

Experimental

Notice: This type is EXPERIMENTAL and may be changed or removed in a later release.

func (NopTL) Helper

func (n NopTL) Helper()

func (NopTL) Log

func (n NopTL) Log(args ...interface{})

type TL

type TL interface {
	Helper()
	Log(args ...interface{})
}

TL is the relevant subset of testing.TB.

Experimental

Notice: This type is EXPERIMENTAL and may be changed or removed in a later release.

type Underlier

type Underlier interface {
	// GetUnderlying returns the testing instance that logging goes to.
	// It returns nil when the test has completed already.
	GetUnderlying() TL

	// GetBuffer grants access to the in-memory copy of the log entries.
	GetBuffer() Buffer
}

Underlier is implemented by the LogSink of this logger. It provides access to additional APIs that are normally hidden behind the Logger API.

Experimental

Notice: This type is EXPERIMENTAL and may be changed or removed in a later release.

Example

package main

import (
	"errors"
	"fmt"
	"time"

	"k8s.io/klog/v2/ktesting"
)

func main() {
	logger := ktesting.NewLogger(ktesting.NopTL{},
		ktesting.NewConfig(
			ktesting.Verbosity(4),
			ktesting.BufferLogs(true),
			ktesting.AnyToString(func(value interface{}) string {
				return fmt.Sprintf("### %+v ###", value)
			}),
		),
	)

	logger.Error(errors.New("failure"), "I failed", "what", "something", "data", struct{ field int }{field: 1})
	logger.WithValues("request", 42).WithValues("anotherValue", "fish").Info("hello world")
	logger.WithValues("request", 42, "anotherValue", "fish").Info("hello world 2", "yetAnotherValue", "thanks")
	logger.WithName("example").Info("with name")
	logger.V(4).Info("higher verbosity")
	logger.V(5).Info("Not captured because of ktesting.Verbosity(4) above. Normally it would be captured because default verbosity is 5.")

	testingLogger, ok := logger.GetSink().(ktesting.Underlier)
	if !ok {
		panic("Should have had a ktesting LogSink!?")
	}

	t := testingLogger.GetUnderlying()
	t.Log("This goes to /dev/null...")

	buffer := testingLogger.GetBuffer()
	fmt.Printf("%s\n", buffer.String())

	log := buffer.Data()
	for i, entry := range log {
		if i > 0 &&
			entry.Timestamp.Sub(log[i-1].Timestamp).Nanoseconds() < 0 {
			fmt.Printf("Unexpected timestamp order: #%d %s > #%d %s", i-1, log[i-1].Timestamp, i, entry.Timestamp)
		}
		// Strip varying time stamp before dumping the struct.
		entry.Timestamp = time.Time{}
		fmt.Printf("log entry #%d: %+v\n", i, entry)
	}

}

Output:

ERROR I failed err="failure" what="something" data=### {field:1} ###
INFO hello world request=### 42 ### anotherValue="fish"
INFO hello world 2 request=### 42 ### anotherValue="fish" yetAnotherValue="thanks"
INFO example: with name
INFO higher verbosity

log entry #0: {Timestamp:0001-01-01 00:00:00 +0000 UTC Type:ERROR Prefix: Message:I failed Verbosity:0 Err:failure WithKVList:[] ParameterKVList:[what something data {field:1}]}
log entry #1: {Timestamp:0001-01-01 00:00:00 +0000 UTC Type:INFO Prefix: Message:hello world Verbosity:0 Err:<nil> WithKVList:[request 42 anotherValue fish] ParameterKVList:[]}
log entry #2: {Timestamp:0001-01-01 00:00:00 +0000 UTC Type:INFO Prefix: Message:hello world 2 Verbosity:0 Err:<nil> WithKVList:[request 42 anotherValue fish] ParameterKVList:[yetAnotherValue thanks]}
log entry #3: {Timestamp:0001-01-01 00:00:00 +0000 UTC Type:INFO Prefix:example Message:with name Verbosity:0 Err:<nil> WithKVList:[] ParameterKVList:[]}
log entry #4: {Timestamp:0001-01-01 00:00:00 +0000 UTC Type:INFO Prefix: Message:higher verbosity Verbosity:4 Err:<nil> WithKVList:[] ParameterKVList:[]}