Skip to content

Commit

Permalink
add slog support
Browse files Browse the repository at this point in the history
When compiled with Go >= 1.21, special support for log/slog gets enabled
automatically:

- The formatting of key/value pairs supports slog.Value and slog.LogValuer,
  regardless of where those come from.
- A slog.GroupValue is formatted as a JSON object.
- The logger returned by klog.Background() and the textlogger
  support usage as a backend for the slog API, via slogr.NewSlogHandler,
  with builtin support for handling a slog.Record. However, -vmodule
  does not work when called like that because stack unwinding during
  the Enabled check finds the wrong source code.
- KObj (= ObjectRef) and the type behind KObjSlice support the
  slog.LogValuer interface and thus get formatted properly by slog backends.

The klogr package doesn't get updated. It shouldn't be used anymore. To make
that clearer, it gets marked as "deprecated".

Examples demonstrate the resulting output. That output has to be exactly
the same when used as test, so pid and time get set to fixed values.
  • Loading branch information
pohly committed Oct 26, 2023
1 parent 00614cd commit 7c5322d
Show file tree
Hide file tree
Showing 16 changed files with 865 additions and 75 deletions.
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
}
_, 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 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 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)
}
}
155 changes: 155 additions & 0 deletions internal/serialize/keyvalues_slog.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,155 @@
//go:build go1.21
// +build go1.21

/*
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 serialize

import (
"bytes"
"fmt"
"log/slog"
"strconv"

"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).
//
// slog.LogValuer does not need to be handled here because the handler will
// already have resolved such special values to the final value for logging.
switch v := v.(type) {
case textWriter:
writeTextWriterValue(b, v)
case slog.Value:
// This must come before fmt.Stringer because slog.Value implements
// fmt.Stringer, but does not produce the output that we want.
b.WriteByte('=')
generateJSON(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 slog.LogValuer:
value := slog.AnyValue(v).Resolve()
if value.Kind() == slog.KindString {
writeStringValue(b, value.String())
} else {
b.WriteByte('=')
generateJSON(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)
}
}

// generateJSON has the same preference for plain strings as KVFormat.
// In contrast to KVFormat it always produces valid JSON with no line breaks.
func generateJSON(b *bytes.Buffer, v interface{}) {
switch v := v.(type) {
case slog.Value:
switch v.Kind() {
case slog.KindGroup:
// Format as a JSON group. We must not involve f.AnyToStringHook (if there is any),
// because there is no guarantee that it produces valid JSON.
b.WriteByte('{')
for i, attr := range v.Group() {
if i > 0 {
b.WriteByte(',')
}
b.WriteString(strconv.Quote(attr.Key))
b.WriteByte(':')
generateJSON(b, attr.Value)
}
b.WriteByte('}')
case slog.KindLogValuer:
generateJSON(b, v.Resolve())
default:
// Peel off the slog.Value wrapper and format the actual value.
generateJSON(b, v.Any())
}
case fmt.Stringer:
b.WriteString(strconv.Quote(StringerToString(v)))
case logr.Marshaler:
generateJSON(b, MarshalerToValue(v))
case slog.LogValuer:
generateJSON(b, slog.AnyValue(v).Resolve().Any())
case string:
b.WriteString(strconv.Quote(v))
case error:
b.WriteString(strconv.Quote(v.Error()))
default:
formatAsJSON(b, v)
}
}
Loading

0 comments on commit 7c5322d

Please sign in to comment.