Merge pull request #384 from pohly/slog

slog support + logr 1.3.0 update

contextual_test.go

@@ -17,7 +17,10 @@ limitations under the License.
 package klog_test
 
 import (
+	"context"
 	"fmt"
+	"runtime"
+	"testing"
 
 	"github.com/go-logr/logr"
 	"k8s.io/klog/v2"
@@ -41,7 +44,7 @@ func ExampleSetLogger() {
 	// Output:
 	// logger after SetLogger: *klog.klogger
 	// logger after SetLoggerWithOptions with ContextualLogger(false): *klog.klogger
-	// logger after SetLoggerWithOptions with ContextualLogger(true): logr.discardLogSink
+	// logger after SetLoggerWithOptions with ContextualLogger(true): <nil>
 }
 
 func ExampleFlushLogger() {
@@ -56,3 +59,43 @@ func ExampleFlushLogger() {
 	// Output:
 	// flushing...
 }
+
+func BenchmarkPassingLogger(b *testing.B) {
+	b.Run("with context", func(b *testing.B) {
+		ctx := klog.NewContext(context.Background(), klog.Background())
+		var finalCtx context.Context
+		for n := b.N; n > 0; n-- {
+			finalCtx = passCtx(ctx)
+		}
+		runtime.KeepAlive(finalCtx)
+	})
+
+	b.Run("without context", func(b *testing.B) {
+		logger := klog.Background()
+		var finalLogger klog.Logger
+		for n := b.N; n > 0; n-- {
+			finalLogger = passLogger(logger)
+		}
+		runtime.KeepAlive(finalLogger)
+	})
+}
+
+func BenchmarkExtractLogger(b *testing.B) {
+	b.Run("from context", func(b *testing.B) {
+		ctx := klog.NewContext(context.Background(), klog.Background())
+		var finalLogger klog.Logger
+		for n := b.N; n > 0; n-- {
+			finalLogger = extractCtx(ctx)
+		}
+		runtime.KeepAlive(finalLogger)
+	})
+}
+
+//go:noinline
+func passCtx(ctx context.Context) context.Context { return ctx }
+
+//go:noinline
+func extractCtx(ctx context.Context) klog.Logger { return klog.FromContext(ctx) }
+
+//go:noinline
+func passLogger(logger klog.Logger) klog.Logger { return logger }

examples/go.mod

@@ -3,7 +3,7 @@ module k8s.io/klog/examples
 go 1.13
 
 require (
-	github.com/go-logr/logr v1.2.2
+	github.com/go-logr/logr v1.3.0
 	github.com/go-logr/zapr v1.2.3
 	github.com/golang/glog v0.0.0-20160126235308-23def4e6c14b
 	go.uber.org/goleak v1.1.12

examples/go.sum

@@ -3,9 +3,9 @@ github.com/benbjohnson/clock v1.1.0/go.mod h1:J11/hYXuz8f4ySSvYwY0FKfm+ezbsZBKZx
 github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
 github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c=
 github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
-github.com/go-logr/logr v1.2.0/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A=
-github.com/go-logr/logr v1.2.2 h1:ahHml/yUpnlb96Rp8HCvtYVPY8ZYpxq3g7UYchIYwbs=
 github.com/go-logr/logr v1.2.2/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A=
+github.com/go-logr/logr v1.3.0 h1:2y3SDp0ZXuc6/cjLSZ+Q3ir+QB9T/iG5yYRXqsagWSY=
+github.com/go-logr/logr v1.3.0/go.mod h1:9T104GzyrTigFIr8wt5mBrctHMim0Nb2HLGrmQ40KvY=
 github.com/go-logr/zapr v1.2.3 h1:a9vnzlIBPQBBkeaR9IuMUfmVOrQlkoC4YfPoFkX3T7A=
 github.com/go-logr/zapr v1.2.3/go.mod h1:eIauM6P8qSvTw5o2ez6UEAfGjQKrxQTl5EoK+Qa2oG4=
 github.com/golang/glog v0.0.0-20160126235308-23def4e6c14b h1:VKtxabqXZkF25pY9ekfRL6a582T4P37/31XEstQ5p58=

go.mod

@@ -2,4 +2,4 @@ module k8s.io/klog/v2
 
 go 1.13
 
-require github.com/go-logr/logr v1.2.0
+require github.com/go-logr/logr v1.3.0

go.sum

@@ -1,2 +1,2 @@
-github.com/go-logr/logr v1.2.0 h1:QK40JKJyMdUDz+h+xvCsru/bJhvG0UxvePV0ufL/AcE=
-github.com/go-logr/logr v1.2.0/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A=
+github.com/go-logr/logr v1.3.0 h1:2y3SDp0ZXuc6/cjLSZ+Q3ir+QB9T/iG5yYRXqsagWSY=
+github.com/go-logr/logr v1.3.0/go.mod h1:9T104GzyrTigFIr8wt5mBrctHMim0Nb2HLGrmQ40KvY=

internal/buffer/buffer.go

@@ -30,6 +30,9 @@ import (
 var (
 	// Pid is inserted into log headers. Can be overridden for tests.
 	Pid = os.Getpid()
+
+	// Time, if set, will be used instead of the actual current time.
+	Time *time.Time
 )
 
 // Buffer holds a single byte.Buffer for reuse. The zero value is ready for
@@ -121,6 +124,9 @@ func (buf *Buffer) FormatHeader(s severity.Severity, file string, line int, now
 
 	// Avoid Fprintf, for speed. The format is so simple that we can do it quickly by hand.
 	// It's worth about 3X. Fprintf is hard.
+	if Time != nil {
+		now = *Time
+	}
 	_, month, day := now.Date()
 	hour, minute, second := now.Clock()
 	// Lmmdd hh:mm:ss.uuuuuu threadid file:line]
@@ -156,6 +162,9 @@ func (buf *Buffer) SprintHeader(s severity.Severity, now time.Time) string {
 
 	// Avoid Fprintf, for speed. The format is so simple that we can do it quickly by hand.
 	// It's worth about 3X. Fprintf is hard.
+	if Time != nil {
+		now = *Time
+	}
 	_, month, day := now.Date()
 	hour, minute, second := now.Clock()
 	// Lmmdd hh:mm:ss.uuuuuu threadid file:line]

internal/serialize/keyvalues.go

@@ -172,73 +172,6 @@ func KVListFormat(b *bytes.Buffer, keysAndValues ...interface{}) {
 	Formatter{}.KVListFormat(b, keysAndValues...)
 }
 
-// KVFormat serializes one key/value pair into the provided buffer.
-// A space gets inserted before the pair.
-func (f Formatter) KVFormat(b *bytes.Buffer, k, v interface{}) {
-	b.WriteByte(' ')
-	// Keys are assumed to be well-formed according to
-	// https://github.com/kubernetes/community/blob/master/contributors/devel/sig-instrumentation/migration-to-structured-logging.md#name-arguments
-	// for the sake of performance. Keys with spaces,
-	// special characters, etc. will break parsing.
-	if sK, ok := k.(string); ok {
-		// Avoid one allocation when the key is a string, which
-		// normally it should be.
-		b.WriteString(sK)
-	} else {
-		b.WriteString(fmt.Sprintf("%s", k))
-	}
-
-	// The type checks are sorted so that more frequently used ones
-	// come first because that is then faster in the common
-	// cases. In Kubernetes, ObjectRef (a Stringer) is more common
-	// than plain strings
-	// (https://github.com/kubernetes/kubernetes/pull/106594#issuecomment-975526235).
-	switch v := v.(type) {
-	case textWriter:
-		writeTextWriterValue(b, v)
-	case fmt.Stringer:
-		writeStringValue(b, StringerToString(v))
-	case string:
-		writeStringValue(b, v)
-	case error:
-		writeStringValue(b, ErrorToString(v))
-	case logr.Marshaler:
-		value := MarshalerToValue(v)
-		// A marshaler that returns a string is useful for
-		// delayed formatting of complex values. We treat this
-		// case like a normal string. This is useful for
-		// multi-line support.
-		//
-		// We could do this by recursively formatting a value,
-		// but that comes with the risk of infinite recursion
-		// if a marshaler returns itself. Instead we call it
-		// only once and rely on it returning the intended
-		// value directly.
-		switch value := value.(type) {
-		case string:
-			writeStringValue(b, value)
-		default:
-			f.formatAny(b, value)
-		}
-	case []byte:
-		// In https://github.com/kubernetes/klog/pull/237 it was decided
-		// to format byte slices with "%+q". The advantages of that are:
-		// - readable output if the bytes happen to be printable
-		// - non-printable bytes get represented as unicode escape
-		//   sequences (\uxxxx)
-		//
-		// The downsides are that we cannot use the faster
-		// strconv.Quote here and that multi-line output is not
-		// supported. If developers know that a byte array is
-		// printable and they want multi-line output, they can
-		// convert the value to string before logging it.
-		b.WriteByte('=')
-		b.WriteString(fmt.Sprintf("%+q", v))
-	default:
-		f.formatAny(b, v)
-	}
-}
-
 func KVFormat(b *bytes.Buffer, k, v interface{}) {
 	Formatter{}.KVFormat(b, k, v)
 }
@@ -251,6 +184,10 @@ func (f Formatter) formatAny(b *bytes.Buffer, v interface{}) {
 		b.WriteString(f.AnyToStringHook(v))
 		return
 	}
+	formatAsJSON(b, v)
+}
+
+func formatAsJSON(b *bytes.Buffer, v interface{}) {
 	encoder := json.NewEncoder(b)
 	l := b.Len()
 	if err := encoder.Encode(v); err != nil {

internal/serialize/keyvalues_no_slog.go

@@ -0,0 +1,97 @@
+//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 serialize
+
+import (
+	"bytes"
+	"fmt"
+
+	"github.com/go-logr/logr"
+)
+
+// KVFormat serializes one key/value pair into the provided buffer.
+// A space gets inserted before the pair.
+func (f Formatter) KVFormat(b *bytes.Buffer, k, v interface{}) {
+	// This is the version without slog support. Must be kept in sync with
+	// the version in keyvalues_slog.go.
+
+	b.WriteByte(' ')
+	// Keys are assumed to be well-formed according to
+	// https://github.com/kubernetes/community/blob/master/contributors/devel/sig-instrumentation/migration-to-structured-logging.md#name-arguments
+	// for the sake of performance. Keys with spaces,
+	// special characters, etc. will break parsing.
+	if sK, ok := k.(string); ok {
+		// Avoid one allocation when the key is a string, which
+		// normally it should be.
+		b.WriteString(sK)
+	} else {
+		b.WriteString(fmt.Sprintf("%s", k))
+	}
+
+	// The type checks are sorted so that more frequently used ones
+	// come first because that is then faster in the common
+	// cases. In Kubernetes, ObjectRef (a Stringer) is more common
+	// than plain strings
+	// (https://github.com/kubernetes/kubernetes/pull/106594#issuecomment-975526235).
+	switch v := v.(type) {
+	case textWriter:
+		writeTextWriterValue(b, v)
+	case fmt.Stringer:
+		writeStringValue(b, StringerToString(v))
+	case string:
+		writeStringValue(b, v)
+	case error:
+		writeStringValue(b, ErrorToString(v))
+	case logr.Marshaler:
+		value := MarshalerToValue(v)
+		// A marshaler that returns a string is useful for
+		// delayed formatting of complex values. We treat this
+		// case like a normal string. This is useful for
+		// multi-line support.
+		//
+		// We could do this by recursively formatting a value,
+		// but that comes with the risk of infinite recursion
+		// if a marshaler returns itself. Instead we call it
+		// only once and rely on it returning the intended
+		// value directly.
+		switch value := value.(type) {
+		case string:
+			writeStringValue(b, value)
+		default:
+			f.formatAny(b, value)
+		}
+	case []byte:
+		// In https://github.com/kubernetes/klog/pull/237 it was decided
+		// to format byte slices with "%+q". The advantages of that are:
+		// - readable output if the bytes happen to be printable
+		// - non-printable bytes get represented as unicode escape
+		//   sequences (\uxxxx)
+		//
+		// The downsides are that we cannot use the faster
+		// strconv.Quote here and that multi-line output is not
+		// supported. If developers know that a byte array is
+		// printable and they want multi-line output, they can
+		// convert the value to string before logging it.
+		b.WriteByte('=')
+		b.WriteString(fmt.Sprintf("%+q", v))
+	default:
+		f.formatAny(b, v)
+	}
+}