Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

slog support + logr 1.3.0 update #384

Merged
merged 2 commits into from
Oct 31, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
45 changes: 44 additions & 1 deletion contextual_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -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"
Expand All @@ -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() {
Expand All @@ -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 }
2 changes: 1 addition & 1 deletion examples/go.mod
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down
4 changes: 2 additions & 2 deletions examples/go.sum
Original file line number Diff line number Diff line change
Expand Up @@ -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=
Expand Down
2 changes: 1 addition & 1 deletion go.mod
Original file line number Diff line number Diff line change
Expand Up @@ -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
4 changes: 2 additions & 2 deletions go.sum
Original file line number Diff line number Diff line change
@@ -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=
9 changes: 9 additions & 0 deletions internal/buffer/buffer.go
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down Expand Up @@ -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
}
Comment on lines +127 to +129

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is there no way to avoid having to do this? From what I can think of, this is mostly test only use case than anything else. I know go test examples need a strict string match. Is there a way we can work around this somehow ? This is more of a question than something that needs to be fixed before we can get this change in.

This one will add a condition check for each of the Format or Sprint header calls unnecessarily.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is needed for Example* style unit tests where the output is matched verbatim. There is no workaround for this, upstream Go recommends to make all output of such tests deterministic.

_, month, day := now.Date()
hour, minute, second := now.Clock()
// Lmmdd hh:mm:ss.uuuuuu threadid file:line]
Expand Down Expand Up @@ -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]
Expand Down
71 changes: 4 additions & 67 deletions internal/serialize/keyvalues.go
Original file line number Diff line number Diff line change
Expand Up @@ -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)
}
Expand All @@ -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 {
Expand Down
97 changes: 97 additions & 0 deletions internal/serialize/keyvalues_no_slog.go
Original file line number Diff line number Diff line change
@@ -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)
}
}
Loading
Loading