From 64618dfe086d569e9f4298df9eb4b4baf228e6f6 Mon Sep 17 00:00:00 2001 From: "dependabot[bot]" <49699333+dependabot[bot]@users.noreply.github.com> Date: Mon, 30 Oct 2023 00:50:01 +0000 Subject: [PATCH 01/27] build(deps): bump ossf/scorecard-action from 2.3.0 to 2.3.1 Bumps [ossf/scorecard-action](https://github.com/ossf/scorecard-action) from 2.3.0 to 2.3.1. - [Release notes](https://github.com/ossf/scorecard-action/releases) - [Changelog](https://github.com/ossf/scorecard-action/blob/main/RELEASE.md) - [Commits](https://github.com/ossf/scorecard-action/compare/483ef80eb98fb506c348f7d62e28055e49fe2398...0864cf19026789058feabb7e87baa5f140aac736) --- updated-dependencies: - dependency-name: ossf/scorecard-action dependency-type: direct:production update-type: version-update:semver-patch ... Signed-off-by: dependabot[bot] --- .github/workflows/scorecard.yml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.github/workflows/scorecard.yml b/.github/workflows/scorecard.yml index 593645a..c3c87ef 100644 --- a/.github/workflows/scorecard.yml +++ b/.github/workflows/scorecard.yml @@ -34,7 +34,7 @@ jobs: persist-credentials: false - name: "Run analysis" - uses: ossf/scorecard-action@483ef80eb98fb506c348f7d62e28055e49fe2398 # v2.3.0 + uses: ossf/scorecard-action@0864cf19026789058feabb7e87baa5f140aac736 # v2.3.1 with: results_file: results.sarif results_format: sarif From e602c1de0cb2ab5e84405c900fc10eb351137d8d Mon Sep 17 00:00:00 2001 From: "dependabot[bot]" <49699333+dependabot[bot]@users.noreply.github.com> Date: Mon, 30 Oct 2023 00:50:06 +0000 Subject: [PATCH 02/27] build(deps): bump github/codeql-action from 2.22.4 to 2.22.5 Bumps [github/codeql-action](https://github.com/github/codeql-action) from 2.22.4 to 2.22.5. - [Release notes](https://github.com/github/codeql-action/releases) - [Changelog](https://github.com/github/codeql-action/blob/main/CHANGELOG.md) - [Commits](https://github.com/github/codeql-action/compare/49abf0ba24d0b7953cb586944e918a0b92074c80...74483a38d39275f33fcff5f35b679b5ca4a26a99) --- updated-dependencies: - dependency-name: github/codeql-action dependency-type: direct:production update-type: version-update:semver-patch ... Signed-off-by: dependabot[bot] --- .github/workflows/scorecard.yml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.github/workflows/scorecard.yml b/.github/workflows/scorecard.yml index 593645a..54ff270 100644 --- a/.github/workflows/scorecard.yml +++ b/.github/workflows/scorecard.yml @@ -59,6 +59,6 @@ jobs: # Upload the results to GitHub's code scanning dashboard. - name: "Upload to code-scanning" - uses: github/codeql-action/upload-sarif@49abf0ba24d0b7953cb586944e918a0b92074c80 # v2.22.4 + uses: github/codeql-action/upload-sarif@74483a38d39275f33fcff5f35b679b5ca4a26a99 # v2.22.5 with: sarif_file: results.sarif From 24eb27c447f2774ee9c30aad1b55cbd54ce6aa7c Mon Sep 17 00:00:00 2001 From: "dependabot[bot]" <49699333+dependabot[bot]@users.noreply.github.com> Date: Mon, 20 Nov 2023 00:11:36 +0000 Subject: [PATCH 03/27] build(deps): bump actions/github-script from 6.4.1 to 7.0.1 Bumps [actions/github-script](https://github.com/actions/github-script) from 6.4.1 to 7.0.1. - [Release notes](https://github.com/actions/github-script/releases) - [Commits](https://github.com/actions/github-script/compare/d7906e4ad0b1822421a7e6a35d5ca353c962f410...60a0d83039c74a4aee543508d2ffcb1c3799cdea) --- updated-dependencies: - dependency-name: actions/github-script dependency-type: direct:production update-type: version-update:semver-major ... Signed-off-by: dependabot[bot] --- .github/workflows/assign.yaml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.github/workflows/assign.yaml b/.github/workflows/assign.yaml index 8f73815..fdab014 100644 --- a/.github/workflows/assign.yaml +++ b/.github/workflows/assign.yaml @@ -16,7 +16,7 @@ jobs: issues: write pull-requests: write steps: - - uses: actions/github-script@d7906e4ad0b1822421a7e6a35d5ca353c962f410 # v6.4.1 + - uses: actions/github-script@60a0d83039c74a4aee543508d2ffcb1c3799cdea # v7.0.1 with: script: | github.rest.issues.addAssignees({ From f36813a8ed4af1a4ea246f7eedb88c6341beb3f7 Mon Sep 17 00:00:00 2001 From: "dependabot[bot]" <49699333+dependabot[bot]@users.noreply.github.com> Date: Mon, 20 Nov 2023 00:11:31 +0000 Subject: [PATCH 04/27] build(deps): bump github/codeql-action from 2.22.5 to 2.22.7 Bumps [github/codeql-action](https://github.com/github/codeql-action) from 2.22.5 to 2.22.7. - [Release notes](https://github.com/github/codeql-action/releases) - [Changelog](https://github.com/github/codeql-action/blob/main/CHANGELOG.md) - [Commits](https://github.com/github/codeql-action/compare/74483a38d39275f33fcff5f35b679b5ca4a26a99...66b90a5db151a8042fa97405c6cf843bbe433f7b) --- updated-dependencies: - dependency-name: github/codeql-action dependency-type: direct:production update-type: version-update:semver-patch ... Signed-off-by: dependabot[bot] --- .github/workflows/scorecard.yml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.github/workflows/scorecard.yml b/.github/workflows/scorecard.yml index 6f891c3..cf3e912 100644 --- a/.github/workflows/scorecard.yml +++ b/.github/workflows/scorecard.yml @@ -59,6 +59,6 @@ jobs: # Upload the results to GitHub's code scanning dashboard. - name: "Upload to code-scanning" - uses: github/codeql-action/upload-sarif@74483a38d39275f33fcff5f35b679b5ca4a26a99 # v2.22.5 + uses: github/codeql-action/upload-sarif@66b90a5db151a8042fa97405c6cf843bbe433f7b # v2.22.7 with: sarif_file: results.sarif From 41d36ee83a11a9205964f6e2f68305c6bd067f80 Mon Sep 17 00:00:00 2001 From: "dependabot[bot]" <49699333+dependabot[bot]@users.noreply.github.com> Date: Mon, 27 Nov 2023 00:54:08 +0000 Subject: [PATCH 05/27] build(deps): bump github/codeql-action from 2.22.7 to 2.22.8 Bumps [github/codeql-action](https://github.com/github/codeql-action) from 2.22.7 to 2.22.8. - [Release notes](https://github.com/github/codeql-action/releases) - [Changelog](https://github.com/github/codeql-action/blob/main/CHANGELOG.md) - [Commits](https://github.com/github/codeql-action/compare/66b90a5db151a8042fa97405c6cf843bbe433f7b...407ffafae6a767df3e0230c3df91b6443ae8df75) --- updated-dependencies: - dependency-name: github/codeql-action dependency-type: direct:production update-type: version-update:semver-patch ... Signed-off-by: dependabot[bot] --- .github/workflows/scorecard.yml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.github/workflows/scorecard.yml b/.github/workflows/scorecard.yml index cf3e912..e3e8ec0 100644 --- a/.github/workflows/scorecard.yml +++ b/.github/workflows/scorecard.yml @@ -59,6 +59,6 @@ jobs: # Upload the results to GitHub's code scanning dashboard. - name: "Upload to code-scanning" - uses: github/codeql-action/upload-sarif@66b90a5db151a8042fa97405c6cf843bbe433f7b # v2.22.7 + uses: github/codeql-action/upload-sarif@407ffafae6a767df3e0230c3df91b6443ae8df75 # v2.22.8 with: sarif_file: results.sarif From 1fffd0744ecf83cc2f47fc18e5fab0bafa81e4ed Mon Sep 17 00:00:00 2001 From: Patrick Ohly Date: Sun, 26 Nov 2023 17:52:52 +0100 Subject: [PATCH 06/27] move slogr into main package This is necessary to give the context handling functions access to the slogr functionality. Functions get renamed to match names in the main package where needed. The slogr package is now deprecated, but continues to be supported as part of the logr v1 API by keeping all exported items as wrappers or aliases for the main package. --- README.md | 28 +++---- {slogr/example => examples/slog}/main.go | 7 +- slogr/sloghandler.go => sloghandler.go | 33 ++++---- slogr.go | 100 +++++++++++++++++++++++ slogr/slogr.go | 76 +++-------------- slogr/slogr_test.go => slogr_test.go | 49 ++++++----- slogr/slogsink.go => slogsink.go | 20 ++--- 7 files changed, 177 insertions(+), 136 deletions(-) rename {slogr/example => examples/slog}/main.go (93%) rename slogr/sloghandler.go => sloghandler.go (83%) create mode 100644 slogr.go rename slogr/slogr_test.go => slogr_test.go (82%) rename slogr/slogsink.go => slogsink.go (85%) diff --git a/README.md b/README.md index a8c29bf..a9b1a4e 100644 --- a/README.md +++ b/README.md @@ -94,8 +94,8 @@ logr design but also left out some parts and changed others: The high-level slog API is explicitly meant to be one of many different APIs that can be layered on top of a shared `slog.Handler`. logr is one such -alternative API, with [interoperability](#slog-interoperability) provided by the [`slogr`](slogr) -package. +alternative API, with [interoperability](#slog-interoperability) provided by +some conversion functions. ### Inspiration @@ -145,24 +145,24 @@ There are implementations for the following logging libraries: ## slog interoperability Interoperability goes both ways, using the `logr.Logger` API with a `slog.Handler` -and using the `slog.Logger` API with a `logr.LogSink`. [slogr](./slogr) provides `NewLogr` and -`NewSlogHandler` API calls to convert between a `logr.Logger` and a `slog.Handler`. +and using the `slog.Logger` API with a `logr.LogSink`. `FromSlogHandler` and +`ToSlogHandler` convert between a `logr.Logger` and a `slog.Handler`. As usual, `slog.New` can be used to wrap such a `slog.Handler` in the high-level -slog API. `slogr` itself leaves that to the caller. +slog API. -## Using a `logr.Sink` as backend for slog +### Using a `logr.LogSink` as backend for slog Ideally, a logr sink implementation should support both logr and slog by -implementing both the normal logr interface(s) and `slogr.SlogSink`. Because +implementing both the normal logr interface(s) and `SlogSink`. Because of a conflict in the parameters of the common `Enabled` method, it is [not possible to implement both slog.Handler and logr.Sink in the same type](https://github.com/golang/go/issues/59110). If both are supported, log calls can go from the high-level APIs to the backend -without the need to convert parameters. `NewLogr` and `NewSlogHandler` can +without the need to convert parameters. `FromSlogHandler` and `ToSlogHandler` can convert back and forth without adding additional wrappers, with one exception: when `Logger.V` was used to adjust the verbosity for a `slog.Handler`, then -`NewSlogHandler` has to use a wrapper which adjusts the verbosity for future +`ToSlogHandler` has to use a wrapper which adjusts the verbosity for future log calls. Such an implementation should also support values that implement specific @@ -187,13 +187,13 @@ Not supporting slog has several drawbacks: These drawbacks are severe enough that applications using a mixture of slog and logr should switch to a different backend. -## Using a `slog.Handler` as backend for logr +### Using a `slog.Handler` as backend for logr Using a plain `slog.Handler` without support for logr works better than the other direction: - All logr verbosity levels can be mapped 1:1 to their corresponding slog level by negating them. -- Stack unwinding is done by the `slogr.SlogSink` and the resulting program +- Stack unwinding is done by the `SlogSink` and the resulting program counter is passed to the `slog.Handler`. - Names added via `Logger.WithName` are gathered and recorded in an additional attribute with `logger` as key and the names separated by slash as value. @@ -205,7 +205,7 @@ ideally support both `logr.Marshaler` and `slog.Valuer`. If compatibility with logr implementations without slog support is not important, then `slog.Valuer` is sufficient. -## Context support for slog +### Context support for slog Storing a logger in a `context.Context` is not supported by slog. `logr.NewContext` and `logr.FromContext` can be used with slog like this @@ -214,13 +214,13 @@ to fill this gap: func HandlerFromContext(ctx context.Context) slog.Handler { logger, err := logr.FromContext(ctx) if err == nil { - return slogr.NewSlogHandler(logger) + return ToSlogHandler(logger) } return slog.Default().Handler() } func ContextWithHandler(ctx context.Context, handler slog.Handler) context.Context { - return logr.NewContext(ctx, slogr.NewLogr(handler)) + return logr.NewContext(ctx, FromSlogHandler(handler)) } The downside is that storing and retrieving a `slog.Handler` needs more diff --git a/slogr/example/main.go b/examples/slog/main.go similarity index 93% rename from slogr/example/main.go rename to examples/slog/main.go index c6379d2..599d156 100644 --- a/slogr/example/main.go +++ b/examples/slog/main.go @@ -28,7 +28,6 @@ import ( "github.com/go-logr/logr" "github.com/go-logr/logr/funcr" - "github.com/go-logr/logr/slogr" ) type e struct { @@ -62,7 +61,7 @@ func main() { Level: slog.Level(-1), } handler := slog.NewJSONHandler(os.Stderr, &opts) - logrLogger := slogr.NewLogr(handler) + logrLogger := logr.FromSlogHandler(handler) logrExample(logrLogger) logrLogger = funcr.NewJSON( @@ -72,7 +71,7 @@ func main() { LogTimestamp: true, Verbosity: 1, }) - slogLogger := slog.New(slogr.NewSlogHandler(logrLogger)) + slogLogger := slog.New(logr.ToSlogHandler(logrLogger)) slogExample(slogLogger) } @@ -91,7 +90,7 @@ func logrExample(log logr.Logger) { func slogExample(log *slog.Logger) { // There's no guarantee that this logs the right source code location. - // It works for Go 1.21.0 by compensating in slogr.NewSlogHandler + // It works for Go 1.21.0 by compensating in logr.ToSlogHandler // for the additional callers, but those might change. log = log.With("saved", "value") log.Info("1) hello", "val1", 1, "val2", map[string]int{"k": 1}) diff --git a/slogr/sloghandler.go b/sloghandler.go similarity index 83% rename from slogr/sloghandler.go rename to sloghandler.go index ec6725c..7d406d7 100644 --- a/slogr/sloghandler.go +++ b/sloghandler.go @@ -17,18 +17,16 @@ See the License for the specific language governing permissions and limitations under the License. */ -package slogr +package logr import ( "context" "log/slog" - - "github.com/go-logr/logr" ) type slogHandler struct { // May be nil, in which case all logs get discarded. - sink logr.LogSink + sink LogSink // Non-nil if sink is non-nil and implements SlogSink. slogSink SlogSink @@ -90,15 +88,15 @@ func (l *slogHandler) Handle(ctx context.Context, record slog.Record) error { // are called by Handle, code in slog gets skipped. // // This offset currently (Go 1.21.0) works for calls through -// slog.New(NewSlogHandler(...)). There's no guarantee that the call +// slog.New(ToSlogHandler(...)). There's no guarantee that the call // chain won't change. Wrapping the handler will also break unwinding. It's // still better than not adjusting at all.... // -// This cannot be done when constructing the handler because NewLogr needs +// This cannot be done when constructing the handler because FromSlogHandler needs // access to the original sink without this adjustment. A second copy would // work, but then WithAttrs would have to be called for both of them. -func (l *slogHandler) sinkWithCallDepth() logr.LogSink { - if sink, ok := l.sink.(logr.CallDepthLogSink); ok { +func (l *slogHandler) sinkWithCallDepth() LogSink { + if sink, ok := l.sink.(CallDepthLogSink); ok { return sink.WithCallDepth(2) } return l.sink @@ -148,21 +146,22 @@ func (l *slogHandler) addGroupPrefix(name string) string { // levelFromSlog adjusts the level by the logger's verbosity and negates it. // It ensures that the result is >= 0. This is necessary because the result is -// passed to a logr.LogSink and that API did not historically document whether +// passed to a LogSink and that API did not historically document whether // levels could be negative or what that meant. // // Some example usage: -// logrV0 := getMyLogger() -// logrV2 := logrV0.V(2) -// slogV2 := slog.New(slogr.NewSlogHandler(logrV2)) -// slogV2.Debug("msg") // =~ logrV2.V(4) =~ logrV0.V(6) -// slogV2.Info("msg") // =~ logrV2.V(0) =~ logrV0.V(2) -// slogv2.Warn("msg") // =~ logrV2.V(-4) =~ logrV0.V(0) +// +// logrV0 := getMyLogger() +// logrV2 := logrV0.V(2) +// slogV2 := slog.New(logr.ToSlogHandler(logrV2)) +// slogV2.Debug("msg") // =~ logrV2.V(4) =~ logrV0.V(6) +// slogV2.Info("msg") // =~ logrV2.V(0) =~ logrV0.V(2) +// slogv2.Warn("msg") // =~ logrV2.V(-4) =~ logrV0.V(0) func (l *slogHandler) levelFromSlog(level slog.Level) int { result := -level - result += l.levelBias // in case the original logr.Logger had a V level + result += l.levelBias // in case the original Logger had a V level if result < 0 { - result = 0 // because logr.LogSink doesn't expect negative V levels + result = 0 // because LogSink doesn't expect negative V levels } return int(result) } diff --git a/slogr.go b/slogr.go new file mode 100644 index 0000000..28a83d0 --- /dev/null +++ b/slogr.go @@ -0,0 +1,100 @@ +//go:build go1.21 +// +build go1.21 + +/* +Copyright 2023 The logr 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 logr + +import ( + "context" + "log/slog" +) + +// FromSlogHandler returns a Logger which writes to the slog.Handler. +// +// The logr verbosity level is mapped to slog levels such that V(0) becomes +// slog.LevelInfo and V(4) becomes slog.LevelDebug. +func FromSlogHandler(handler slog.Handler) Logger { + if handler, ok := handler.(*slogHandler); ok { + if handler.sink == nil { + return Discard() + } + return New(handler.sink).V(int(handler.levelBias)) + } + return New(&slogSink{handler: handler}) +} + +// ToSlogHandler returns a slog.Handler which writes to the same sink as the Logger. +// +// The returned logger writes all records with level >= slog.LevelError as +// error log entries with LogSink.Error, regardless of the verbosity level of +// the Logger: +// +// logger := +// slog.New(ToSlogHandler(logger.V(10))).Error(...) -> logSink.Error(...) +// +// The level of all other records gets reduced by the verbosity +// level of the Logger and the result is negated. If it happens +// to be negative, then it gets replaced by zero because a LogSink +// is not expected to handled negative levels: +// +// slog.New(ToSlogHandler(logger)).Debug(...) -> logger.GetSink().Info(level=4, ...) +// slog.New(ToSlogHandler(logger)).Warning(...) -> logger.GetSink().Info(level=0, ...) +// slog.New(ToSlogHandler(logger)).Info(...) -> logger.GetSink().Info(level=0, ...) +// slog.New(ToSlogHandler(logger.V(4))).Info(...) -> logger.GetSink().Info(level=4, ...) +func ToSlogHandler(logger Logger) slog.Handler { + if sink, ok := logger.GetSink().(*slogSink); ok && logger.GetV() == 0 { + return sink.handler + } + + handler := &slogHandler{sink: logger.GetSink(), levelBias: slog.Level(logger.GetV())} + if slogSink, ok := handler.sink.(SlogSink); ok { + handler.slogSink = slogSink + } + return handler +} + +// SlogSink is an optional interface that a LogSink can implement to support +// logging through the slog.Logger or slog.Handler APIs better. It then should +// also support special slog values like slog.Group. When used as a +// slog.Handler, the advantages are: +// +// - stack unwinding gets avoided in favor of logging the pre-recorded PC, +// as intended by slog +// - proper grouping of key/value pairs via WithGroup +// - verbosity levels > slog.LevelInfo can be recorded +// - less overhead +// +// Both APIs (Logger and slog.Logger/Handler) then are supported equally +// well. Developers can pick whatever API suits them better and/or mix +// packages which use either API in the same binary with a common logging +// implementation. +// +// This interface is necessary because the type implementing the LogSink +// interface cannot also implement the slog.Handler interface due to the +// different prototype of the common Enabled method. +// +// An implementation could support both interfaces in two different types, but then +// additional interfaces would be needed to convert between those types in FromSlogHandler +// and ToSlogHandler. +type SlogSink interface { + LogSink + + Handle(ctx context.Context, record slog.Record) error + WithAttrs(attrs []slog.Attr) SlogSink + WithGroup(name string) SlogSink +} diff --git a/slogr/slogr.go b/slogr/slogr.go index eb519ae..4fdf3b6 100644 --- a/slogr/slogr.go +++ b/slogr/slogr.go @@ -23,10 +23,11 @@ limitations under the License. // // See the README in the top-level [./logr] package for a discussion of // interoperability. +// +// Deprecated: use the main logr package instead. package slogr import ( - "context" "log/slog" "github.com/go-logr/logr" @@ -34,75 +35,20 @@ import ( // NewLogr returns a logr.Logger which writes to the slog.Handler. // -// The logr verbosity level is mapped to slog levels such that V(0) becomes -// slog.LevelInfo and V(4) becomes slog.LevelDebug. +// Deprecated: use [logr.FromSlogHandler] instead. func NewLogr(handler slog.Handler) logr.Logger { - if handler, ok := handler.(*slogHandler); ok { - if handler.sink == nil { - return logr.Discard() - } - return logr.New(handler.sink).V(int(handler.levelBias)) - } - return logr.New(&slogSink{handler: handler}) + return logr.FromSlogHandler(handler) } -// NewSlogHandler returns a slog.Handler which writes to the same sink as the logr.Logger. -// -// The returned logger writes all records with level >= slog.LevelError as -// error log entries with LogSink.Error, regardless of the verbosity level of -// the logr.Logger: -// -// logger := -// slog.New(NewSlogHandler(logger.V(10))).Error(...) -> logSink.Error(...) +// ToSlogHandler returns a slog.Handler which writes to the same sink as the logr.Logger. // -// The level of all other records gets reduced by the verbosity -// level of the logr.Logger and the result is negated. If it happens -// to be negative, then it gets replaced by zero because a LogSink -// is not expected to handled negative levels: -// -// slog.New(NewSlogHandler(logger)).Debug(...) -> logger.GetSink().Info(level=4, ...) -// slog.New(NewSlogHandler(logger)).Warning(...) -> logger.GetSink().Info(level=0, ...) -// slog.New(NewSlogHandler(logger)).Info(...) -> logger.GetSink().Info(level=0, ...) -// slog.New(NewSlogHandler(logger.V(4))).Info(...) -> logger.GetSink().Info(level=4, ...) -func NewSlogHandler(logger logr.Logger) slog.Handler { - if sink, ok := logger.GetSink().(*slogSink); ok && logger.GetV() == 0 { - return sink.handler - } - - handler := &slogHandler{sink: logger.GetSink(), levelBias: slog.Level(logger.GetV())} - if slogSink, ok := handler.sink.(SlogSink); ok { - handler.slogSink = slogSink - } - return handler +// Deprecated: use [logr.ToSlogHandler] instead. +func ToSlogHandler(logger logr.Logger) slog.Handler { + return logr.ToSlogHandler(logger) } // SlogSink is an optional interface that a LogSink can implement to support -// logging through the slog.Logger or slog.Handler APIs better. It then should -// also support special slog values like slog.Group. When used as a -// slog.Handler, the advantages are: +// logging through the slog.Logger or slog.Handler APIs better. // -// - stack unwinding gets avoided in favor of logging the pre-recorded PC, -// as intended by slog -// - proper grouping of key/value pairs via WithGroup -// - verbosity levels > slog.LevelInfo can be recorded -// - less overhead -// -// Both APIs (logr.Logger and slog.Logger/Handler) then are supported equally -// well. Developers can pick whatever API suits them better and/or mix -// packages which use either API in the same binary with a common logging -// implementation. -// -// This interface is necessary because the type implementing the LogSink -// interface cannot also implement the slog.Handler interface due to the -// different prototype of the common Enabled method. -// -// An implementation could support both interfaces in two different types, but then -// additional interfaces would be needed to convert between those types in NewLogr -// and NewSlogHandler. -type SlogSink interface { - logr.LogSink - - Handle(ctx context.Context, record slog.Record) error - WithAttrs(attrs []slog.Attr) SlogSink - WithGroup(name string) SlogSink -} +// Deprecated: use [logr.SlogSink] instead. +type SlogSink = logr.SlogSink diff --git a/slogr/slogr_test.go b/slogr_test.go similarity index 82% rename from slogr/slogr_test.go rename to slogr_test.go index 2e5f0ff..fff6fb5 100644 --- a/slogr/slogr_test.go +++ b/slogr_test.go @@ -17,7 +17,7 @@ See the License for the specific language governing permissions and limitations under the License. */ -package slogr_test +package logr_test import ( "bytes" @@ -36,7 +36,6 @@ import ( "github.com/go-logr/logr" "github.com/go-logr/logr/funcr" - "github.com/go-logr/logr/slogr" ) var debugWithoutTime = &slog.HandlerOptions{ @@ -49,12 +48,12 @@ var debugWithoutTime = &slog.HandlerOptions{ Level: slog.LevelDebug, } -func ExampleNew() { - logger := slogr.NewLogr(slog.NewTextHandler(os.Stdout, debugWithoutTime)) +func ExampleFromSlogHandler() { + logrLogger := logr.FromSlogHandler(slog.NewTextHandler(os.Stdout, debugWithoutTime)) - logger.Info("hello world") - logger.Error(errors.New("fake error"), "ignore me") - logger.WithValues("x", 1, "y", 2).WithValues("str", "abc").WithName("foo").WithName("bar").V(4).Info("with values, verbosity and name") + logrLogger.Info("hello world") + logrLogger.Error(errors.New("fake error"), "ignore me") + logrLogger.WithValues("x", 1, "y", 2).WithValues("str", "abc").WithName("foo").WithName("bar").V(4).Info("with values, verbosity and name") // Output: // level=INFO msg="hello world" @@ -62,7 +61,7 @@ func ExampleNew() { // level=DEBUG msg="with values, verbosity and name" x=1 y=2 str=abc logger=foo/bar } -func ExampleNewSlogLogger() { +func ExampleToSlogHandler() { funcrLogger := funcr.New(func(prefix, args string) { if prefix != "" { fmt.Fprintln(os.Stdout, prefix, args) @@ -73,13 +72,13 @@ func ExampleNewSlogLogger() { Verbosity: 10, }) - logger := slog.New(slogr.NewSlogHandler(funcrLogger)) - logger.Info("hello world") - logger.Error("ignore me", "err", errors.New("fake error")) - logger.With("x", 1, "y", 2).WithGroup("group").With("str", "abc").Warn("with values and group") + slogLogger := slog.New(logr.ToSlogHandler(funcrLogger)) + slogLogger.Info("hello world") + slogLogger.Error("ignore me", "err", errors.New("fake error")) + slogLogger.With("x", 1, "y", 2).WithGroup("group").With("str", "abc").Warn("with values and group") - logger = slog.New(slogr.NewSlogHandler(funcrLogger.V(int(-slog.LevelDebug)))) - logger.Info("info message reduced to debug level") + slogLogger = slog.New(logr.ToSlogHandler(funcrLogger.V(int(-slog.LevelDebug)))) + slogLogger.Info("info message reduced to debug level") // Output: // "level"=0 "msg"="hello world" @@ -92,7 +91,7 @@ func TestWithCallDepth(t *testing.T) { debugWithCaller := *debugWithoutTime debugWithCaller.AddSource = true var buffer bytes.Buffer - logger := slogr.NewLogr(slog.NewTextHandler(&buffer, &debugWithCaller)) + logger := logr.FromSlogHandler(slog.NewTextHandler(&buffer, &debugWithCaller)) logHelper(logger) _, file, line, _ := runtime.Caller(0) @@ -116,7 +115,7 @@ func TestJSONHandler(t *testing.T) { } var _ logr.LogSink = testSlogSink{} -var _ slogr.SlogSink = testSlogSink{} +var _ logr.SlogSink = testSlogSink{} // testSlogSink is only used through slog and thus doesn't need to implement the // normal LogSink methods. @@ -134,10 +133,10 @@ func (s testSlogSink) WithValues(...interface{}) logr.LogSink { return s } func (s testSlogSink) Handle(ctx context.Context, record slog.Record) error { return s.handler.Handle(ctx, record) } -func (s testSlogSink) WithAttrs(attrs []slog.Attr) slogr.SlogSink { +func (s testSlogSink) WithAttrs(attrs []slog.Attr) logr.SlogSink { return testSlogSink{handler: s.handler.WithAttrs(attrs)} } -func (s testSlogSink) WithGroup(name string) slogr.SlogSink { +func (s testSlogSink) WithGroup(name string) logr.SlogSink { return testSlogSink{handler: s.handler.WithGroup(name)} } @@ -178,7 +177,7 @@ func TestFuncrHandler(t *testing.T) { func testSlog(t *testing.T, createLogger func(buffer *bytes.Buffer) logr.Logger, exceptions ...string) { var buffer bytes.Buffer logger := createLogger(&buffer) - handler := slogr.NewSlogHandler(logger) + handler := logr.ToSlogHandler(logger) err := slogtest.TestHandler(handler, func() []map[string]any { var ms []map[string]any for _, line := range bytes.Split(buffer.Bytes(), []byte{'\n'}) { @@ -223,28 +222,28 @@ func containsOne(hay string, needles ...string) bool { } func TestDiscard(t *testing.T) { - logger := slog.New(slogr.NewSlogHandler(logr.Discard())) + logger := slog.New(logr.ToSlogHandler(logr.Discard())) logger.WithGroup("foo").With("x", 1).Info("hello") } func TestConversion(t *testing.T) { d := logr.Discard() - d2 := slogr.NewLogr(slogr.NewSlogHandler(d)) + d2 := logr.FromSlogHandler(logr.ToSlogHandler(d)) expectEqual(t, d, d2) e := logr.Logger{} - e2 := slogr.NewLogr(slogr.NewSlogHandler(e)) + e2 := logr.FromSlogHandler(logr.ToSlogHandler(e)) expectEqual(t, e, e2) f := funcr.New(func(prefix, args string) {}, funcr.Options{}) - f2 := slogr.NewLogr(slogr.NewSlogHandler(f)) + f2 := logr.FromSlogHandler(logr.ToSlogHandler(f)) expectEqual(t, f, f2) text := slog.NewTextHandler(io.Discard, nil) - text2 := slogr.NewSlogHandler(slogr.NewLogr(text)) + text2 := logr.ToSlogHandler(logr.FromSlogHandler(text)) expectEqual(t, text, text2) - text3 := slogr.NewSlogHandler(slogr.NewLogr(text).V(1)) + text3 := logr.ToSlogHandler(logr.FromSlogHandler(text).V(1)) if handler, ok := text3.(interface { GetLevel() slog.Level }); ok { diff --git a/slogr/slogsink.go b/slogsink.go similarity index 85% rename from slogr/slogsink.go rename to slogsink.go index 6fbac56..93fa4e5 100644 --- a/slogr/slogsink.go +++ b/slogsink.go @@ -17,24 +17,22 @@ See the License for the specific language governing permissions and limitations under the License. */ -package slogr +package logr import ( "context" "log/slog" "runtime" "time" - - "github.com/go-logr/logr" ) var ( - _ logr.LogSink = &slogSink{} - _ logr.CallDepthLogSink = &slogSink{} - _ Underlier = &slogSink{} + _ LogSink = &slogSink{} + _ CallDepthLogSink = &slogSink{} + _ Underlier = &slogSink{} ) -// Underlier is implemented by the LogSink returned by NewLogr. +// Underlier is implemented by the LogSink returned by NewFromLogHandler. type Underlier interface { // GetUnderlying returns the Handler used by the LogSink. GetUnderlying() slog.Handler @@ -54,7 +52,7 @@ type slogSink struct { handler slog.Handler } -func (l *slogSink) Init(info logr.RuntimeInfo) { +func (l *slogSink) Init(info RuntimeInfo) { l.callDepth = info.CallDepth } @@ -62,7 +60,7 @@ func (l *slogSink) GetUnderlying() slog.Handler { return l.handler } -func (l *slogSink) WithCallDepth(depth int) logr.LogSink { +func (l *slogSink) WithCallDepth(depth int) LogSink { newLogger := *l newLogger.callDepth += depth return &newLogger @@ -96,7 +94,7 @@ func (l *slogSink) log(err error, msg string, level slog.Level, kvList ...interf l.handler.Handle(context.Background(), record) } -func (l slogSink) WithName(name string) logr.LogSink { +func (l slogSink) WithName(name string) LogSink { if l.name != "" { l.name = l.name + "/" } @@ -104,7 +102,7 @@ func (l slogSink) WithName(name string) logr.LogSink { return &l } -func (l slogSink) WithValues(kvList ...interface{}) logr.LogSink { +func (l slogSink) WithValues(kvList ...interface{}) LogSink { l.handler = l.handler.WithAttrs(kvListToAttrs(kvList...)) return &l } From 6151b2fb393dfc6610deb5887d2895d099cc5a76 Mon Sep 17 00:00:00 2001 From: Patrick Ohly Date: Sun, 26 Nov 2023 17:53:45 +0100 Subject: [PATCH 07/27] support a slog.Logger pointer in a context Conversion is done on demand. A program which uses either slog or logr for logging remains as efficient as before. What is less efficient is storing a logger of one type and then retrieving it as the other. Ideally, reusable packages should avoid using a slog.Logger and prefer logr.Logger instead when retrieving a logger from a context. There is a significant amount of packages which already work that way (Kubernetes and related packages), while storing and retrieving a logr.Logger is new and not done anywhere yet. Emulating existing behavior ensures better performance. --- README.md | 49 ++++++++++++++++++---------- context.go | 33 +++++++++++++++++++ context_noslog.go | 49 ++++++++++++++++++++++++++++ context_slog.go | 83 +++++++++++++++++++++++++++++++++++++++++++++++ logr.go | 43 ------------------------ 5 files changed, 196 insertions(+), 61 deletions(-) create mode 100644 context.go create mode 100644 context_noslog.go create mode 100644 context_slog.go diff --git a/README.md b/README.md index a9b1a4e..8969526 100644 --- a/README.md +++ b/README.md @@ -91,6 +91,7 @@ logr design but also left out some parts and changed others: | Adding a name to a logger | `WithName` | no API | | Modify verbosity of log entries in a call chain | `V` | no API | | Grouping of key/value pairs | not supported | `WithGroup`, `GroupValue` | +| Pass context for extracting additional values | no API | API variants like `InfoCtx` | The high-level slog API is explicitly meant to be one of many different APIs that can be layered on top of a shared `slog.Handler`. logr is one such @@ -208,24 +209,36 @@ with logr implementations without slog support is not important, then ### Context support for slog Storing a logger in a `context.Context` is not supported by -slog. `logr.NewContext` and `logr.FromContext` can be used with slog like this -to fill this gap: - - func HandlerFromContext(ctx context.Context) slog.Handler { - logger, err := logr.FromContext(ctx) - if err == nil { - return ToSlogHandler(logger) - } - return slog.Default().Handler() - } - - func ContextWithHandler(ctx context.Context, handler slog.Handler) context.Context { - return logr.NewContext(ctx, FromSlogHandler(handler)) - } - -The downside is that storing and retrieving a `slog.Handler` needs more -allocations compared to using a `logr.Logger`. Therefore the recommendation is -to use the `logr.Logger` API in code which uses contextual logging. +slog. `NewContextWithSlogLogger` and `FromContextAsSlogLogger` can be +used to fill this gap. They store and retrieve a `slog.Logger` pointer +under the same context key that is also used by `NewContext` and +`FromContext` for `logr.Logger` value. + +When `NewContextWithSlogLogger` is followed by `FromContext`, the latter will +automatically convert the `slog.Logger` to a +`logr.Logger`. `FromContextAsSlogLogger` does the same for the other direction. + +With this approach, binaries which use either slog or logr are as efficient as +possible with no unnecessary allocations. This is also why the API stores a +`slog.Logger` pointer: when storing a `slog.Handler`, creating a `slog.Logger` +on retrieval would need to allocate one. + +The downside is that switching back and forth needs more allocations. Because +logr is the API that is already in use by different packages, in particular +Kubernetes, the recommendation is to use the `logr.Logger` API in code which +uses contextual logging. + +An alternative to adding values to a logger and storing that logger in the +context is to store the values in the context and to configure a logging +backend to extract those values when emitting log entries. This only works when +log calls are passed the context, which is not supported by the logr API. + +With the slog API, it is possible, but not +required. https://github.com/veqryn/slog-context is a package for slog which +provides additional support code for this approach. It also contains wrappers +for the context functions in logr, so developers who prefer to not use the logr +APIs directly can use those instead and the resulting code will still be +interoperable with logr. ## FAQ diff --git a/context.go b/context.go new file mode 100644 index 0000000..de8bcc3 --- /dev/null +++ b/context.go @@ -0,0 +1,33 @@ +/* +Copyright 2023 The logr 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 logr + +// contextKey is how we find Loggers in a context.Context. With Go < 1.21, +// the value is always a Logger value. With Go >= 1.21, the value can be a +// Logger value or a slog.Logger pointer. +type contextKey struct{} + +// notFoundError exists to carry an IsNotFound method. +type notFoundError struct{} + +func (notFoundError) Error() string { + return "no logr.Logger was present" +} + +func (notFoundError) IsNotFound() bool { + return true +} diff --git a/context_noslog.go b/context_noslog.go new file mode 100644 index 0000000..f012f9a --- /dev/null +++ b/context_noslog.go @@ -0,0 +1,49 @@ +//go:build !go1.21 +// +build !go1.21 + +/* +Copyright 2019 The logr 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 logr + +import ( + "context" +) + +// FromContext returns a Logger from ctx or an error if no Logger is found. +func FromContext(ctx context.Context) (Logger, error) { + if v, ok := ctx.Value(contextKey{}).(Logger); ok { + return v, nil + } + + return Logger{}, notFoundError{} +} + +// FromContextOrDiscard returns a Logger from ctx. If no Logger is found, this +// returns a Logger that discards all log messages. +func FromContextOrDiscard(ctx context.Context) Logger { + if v, ok := ctx.Value(contextKey{}).(Logger); ok { + return v + } + + return Discard() +} + +// NewContext returns a new Context, derived from ctx, which carries the +// provided Logger. +func NewContext(ctx context.Context, logger Logger) context.Context { + return context.WithValue(ctx, contextKey{}, logger) +} diff --git a/context_slog.go b/context_slog.go new file mode 100644 index 0000000..065ef0b --- /dev/null +++ b/context_slog.go @@ -0,0 +1,83 @@ +//go:build go1.21 +// +build go1.21 + +/* +Copyright 2019 The logr 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 logr + +import ( + "context" + "fmt" + "log/slog" +) + +// FromContext returns a Logger from ctx or an error if no Logger is found. +func FromContext(ctx context.Context) (Logger, error) { + v := ctx.Value(contextKey{}) + if v == nil { + return Logger{}, notFoundError{} + } + + switch v := v.(type) { + case Logger: + return v, nil + case *slog.Logger: + return FromSlogHandler(v.Handler()), nil + default: + // Not reached. + panic(fmt.Sprintf("unexpected value type for logr context key: %T", v)) + } +} + +// FromContextAsSlogLogger returns a slog.Logger from ctx or nil if no such Logger is found. +func FromContextAsSlogLogger(ctx context.Context) *slog.Logger { + v := ctx.Value(contextKey{}) + if v == nil { + return nil + } + + switch v := v.(type) { + case Logger: + return slog.New(ToSlogHandler(v)) + case *slog.Logger: + return v + default: + // Not reached. + panic(fmt.Sprintf("unexpected value type for logr context key: %T", v)) + } +} + +// FromContextOrDiscard returns a Logger from ctx. If no Logger is found, this +// returns a Logger that discards all log messages. +func FromContextOrDiscard(ctx context.Context) Logger { + if logger, err := FromContext(ctx); err == nil { + return logger + } + return Discard() +} + +// NewContext returns a new Context, derived from ctx, which carries the +// provided Logger. +func NewContext(ctx context.Context, logger Logger) context.Context { + return context.WithValue(ctx, contextKey{}, logger) +} + +// NewContextWithSlogLogger returns a new Context, derived from ctx, which carries the +// provided slog.Logger. +func NewContextWithSlogLogger(ctx context.Context, logger *slog.Logger) context.Context { + return context.WithValue(ctx, contextKey{}, logger) +} diff --git a/logr.go b/logr.go index 2a5075a..b4428e1 100644 --- a/logr.go +++ b/logr.go @@ -207,10 +207,6 @@ limitations under the License. // those. package logr -import ( - "context" -) - // New returns a new Logger instance. This is primarily used by libraries // implementing LogSink, rather than end users. Passing a nil sink will create // a Logger which discards all log lines. @@ -410,45 +406,6 @@ func (l Logger) IsZero() bool { return l.sink == nil } -// contextKey is how we find Loggers in a context.Context. -type contextKey struct{} - -// FromContext returns a Logger from ctx or an error if no Logger is found. -func FromContext(ctx context.Context) (Logger, error) { - if v, ok := ctx.Value(contextKey{}).(Logger); ok { - return v, nil - } - - return Logger{}, notFoundError{} -} - -// notFoundError exists to carry an IsNotFound method. -type notFoundError struct{} - -func (notFoundError) Error() string { - return "no logr.Logger was present" -} - -func (notFoundError) IsNotFound() bool { - return true -} - -// FromContextOrDiscard returns a Logger from ctx. If no Logger is found, this -// returns a Logger that discards all log messages. -func FromContextOrDiscard(ctx context.Context) Logger { - if v, ok := ctx.Value(contextKey{}).(Logger); ok { - return v - } - - return Discard() -} - -// NewContext returns a new Context, derived from ctx, which carries the -// provided Logger. -func NewContext(ctx context.Context, logger Logger) context.Context { - return context.WithValue(ctx, contextKey{}, logger) -} - // RuntimeInfo holds information that the logr "core" library knows which // LogSinks might want to know. type RuntimeInfo struct { From 58f101ea73be4259b3998beeeb05bc2ede045fe5 Mon Sep 17 00:00:00 2001 From: Tim Hockin Date: Fri, 1 Dec 2023 13:53:46 -0800 Subject: [PATCH 08/27] Fix bug in slog support carrying the wrong sink --- sloghandler.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/sloghandler.go b/sloghandler.go index 7d406d7..7d13002 100644 --- a/sloghandler.go +++ b/sloghandler.go @@ -130,7 +130,7 @@ func (l *slogHandler) WithGroup(name string) slog.Handler { copy := *l if l.slogSink != nil { copy.slogSink = l.slogSink.WithGroup(name) - copy.sink = l.slogSink + copy.sink = copy.slogSink } else { copy.groupPrefix = copy.addGroupPrefix(name) } From 5153ab27bb191eadf7c692e3fd501b4dd5b6efdf Mon Sep 17 00:00:00 2001 From: Patrick Ohly Date: Mon, 4 Dec 2023 13:29:06 +0100 Subject: [PATCH 09/27] unit tests with full SlogSink mock implementation This turns testLogSink into an implementation of SlogSink if slog is supported, then runs through some scenarios where values get added using different APIs. The end result gets compared by formatting with the slog JSON handler because that is easier than writing custom code for a deep-equal comparison of slog attributes. The "with-group-and-logr-values" is the case which was broken. --- logr_noslog_test.go | 23 +++++ logr_slog_test.go | 218 ++++++++++++++++++++++++++++++++++++++++++++ logr_test.go | 9 ++ 3 files changed, 250 insertions(+) create mode 100644 logr_noslog_test.go create mode 100644 logr_slog_test.go diff --git a/logr_noslog_test.go b/logr_noslog_test.go new file mode 100644 index 0000000..c449810 --- /dev/null +++ b/logr_noslog_test.go @@ -0,0 +1,23 @@ +//go:build !go1.21 +// +build !go1.21 + +/* +Copyright 2023 The logr 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 logr + +//nolint:unused +type testSlogSink struct{} diff --git a/logr_slog_test.go b/logr_slog_test.go new file mode 100644 index 0000000..7712235 --- /dev/null +++ b/logr_slog_test.go @@ -0,0 +1,218 @@ +//go:build go1.21 +// +build go1.21 + +/* +Copyright 2023 The logr 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 logr + +import ( + "bytes" + "context" + "log/slog" + "testing" + "time" +) + +var _ SlogSink = &testLogSink{} + +// testSlogSink gets embedded in testLogSink to add slog-specific fields +// which are only available when slog is supported by Go. +type testSlogSink struct { + attrs []slog.Attr + groups []string + + fnHandle func(l *testLogSink, ctx context.Context, record slog.Record) + fnWithAttrs func(l *testLogSink, attrs []slog.Attr) + fnWithGroup func(l *testLogSink, name string) +} + +func (l *testLogSink) Handle(ctx context.Context, record slog.Record) error { + if l.fnHandle != nil { + l.fnHandle(l, ctx, record) + } + return nil +} + +func (l *testLogSink) WithAttrs(attrs []slog.Attr) SlogSink { + if l.fnWithAttrs != nil { + l.fnWithAttrs(l, attrs) + } + out := *l + n := len(out.attrs) + out.attrs = append(out.attrs[:n:n], attrs...) + return &out +} + +func (l *testLogSink) WithGroup(name string) SlogSink { + if l.fnWithGroup != nil { + l.fnWithGroup(l, name) + } + out := *l + n := len(out.groups) + out.groups = append(out.groups[:n:n], name) + return &out +} + +func withAttrs(record slog.Record, attrs ...slog.Attr) slog.Record { + record = record.Clone() + record.AddAttrs(attrs...) + return record +} + +func toJSON(record slog.Record) string { + var buffer bytes.Buffer + record.Time = time.Time{} + handler := slog.NewJSONHandler(&buffer, nil) + if err := handler.Handle(context.Background(), record); err != nil { + return err.Error() + } + return buffer.String() +} + +func TestToSlogHandler(t *testing.T) { + lvlThreshold := 0 + actualCalledHandle := 0 + var actualRecord slog.Record + + sink := &testLogSink{} + logger := New(sink) + + sink.fnEnabled = func(lvl int) bool { + return lvl <= lvlThreshold + } + + sink.fnHandle = func(l *testLogSink, ctx context.Context, record slog.Record) { + actualCalledHandle++ + + // Combine attributes from sink and call. Ordering of WithValues and WithAttrs + // is wrong, but good enough for test cases. + var values slog.Record + values.Add(l.withValues...) + var attrs []any + add := func(attr slog.Attr) bool { + attrs = append(attrs, attr) + return true + } + values.Attrs(add) + record.Attrs(add) + for _, attr := range l.attrs { + attrs = append(attrs, attr) + } + + // Wrap them in groups - not quite correct for WithValues that + // follows WithGroup, but good enough for test cases. + for i := len(l.groups) - 1; i >= 0; i-- { + attrs = []any{slog.Group(l.groups[i], attrs...)} + } + + actualRecord = slog.Record{ + Level: record.Level, + Message: record.Message, + } + actualRecord.Add(attrs...) + } + + verify := func(t *testing.T, expectedRecord slog.Record) { + actual := toJSON(actualRecord) + expected := toJSON(expectedRecord) + if expected != actual { + t.Errorf("JSON dump did not match, expected:\n%s\nGot:\n%s\n", expected, actual) + } + } + + reset := func() { + lvlThreshold = 0 + actualCalledHandle = 0 + actualRecord = slog.Record{} + } + + testcases := map[string]struct { + run func() + expectedRecord slog.Record + }{ + "simple": { + func() { slog.New(ToSlogHandler(logger)).Info("simple") }, + slog.Record{Message: "simple"}, + }, + + "disabled": { + func() { slog.New(ToSlogHandler(logger.V(1))).Info("") }, + slog.Record{}, + }, + + "enabled": { + func() { + lvlThreshold = 1 + slog.New(ToSlogHandler(logger.V(1))).Info("enabled") + }, + slog.Record{Level: -1, Message: "enabled"}, + }, + + "error": { + func() { slog.New(ToSlogHandler(logger.V(100))).Error("error") }, + slog.Record{Level: slog.LevelError, Message: "error"}, + }, + + "with-parameters": { + func() { slog.New(ToSlogHandler(logger)).Info("", "answer", 42, "foo", "bar") }, + withAttrs(slog.Record{}, slog.Int("answer", 42), slog.String("foo", "bar")), + }, + + "with-values": { + func() { slog.New(ToSlogHandler(logger.WithValues("answer", 42, "foo", "bar"))).Info("") }, + withAttrs(slog.Record{}, slog.Int("answer", 42), slog.String("foo", "bar")), + }, + + "with-group": { + func() { slog.New(ToSlogHandler(logger)).WithGroup("group").Info("", "answer", 42, "foo", "bar") }, + withAttrs(slog.Record{}, slog.Group("group", slog.Int("answer", 42), slog.String("foo", "bar"))), + }, + + "with-values-and-group": { + func() { + slog.New(ToSlogHandler(logger.WithValues("answer", 42, "foo", "bar"))).WithGroup("group").Info("") + }, + // Behavior of testLogSink is not quite correct here. + withAttrs(slog.Record{}, slog.Group("group", slog.Int("answer", 42), slog.String("foo", "bar"))), + }, + + "with-group-and-values": { + func() { + slog.New(ToSlogHandler(logger)).WithGroup("group").With("answer", 42, "foo", "bar").Info("") + }, + withAttrs(slog.Record{}, slog.Group("group", slog.Int("answer", 42), slog.String("foo", "bar"))), + }, + + "with-group-and-logr-values": { + func() { + slogLogger := slog.New(ToSlogHandler(logger)).WithGroup("group") + logrLogger := FromSlogHandler(slogLogger.Handler()).WithValues("answer", 42, "foo", "bar") + slogLogger = slog.New(ToSlogHandler(logrLogger)) + slogLogger.Info("") + }, + withAttrs(slog.Record{}, slog.Group("group", slog.Int("answer", 42), slog.String("foo", "bar"))), + }, + } + + for name, tc := range testcases { + t.Run(name, func(t *testing.T) { + tc.run() + verify(t, tc.expectedRecord) + reset() + }) + } +} diff --git a/logr_test.go b/logr_test.go index df60cb8..3899013 100644 --- a/logr_test.go +++ b/logr_test.go @@ -33,6 +33,13 @@ type testLogSink struct { fnError func(err error, msg string, kv ...any) fnWithValues func(kv ...any) fnWithName func(name string) + + withValues []any + + // testSlogSink contains some additional fields if (and only if) slog is supported by Go. + // See logr_slog_test.go. + //nolint:unused // Only unused with Go < 1.21. + testSlogSink } var _ LogSink = &testLogSink{} @@ -67,6 +74,8 @@ func (l *testLogSink) WithValues(kv ...any) LogSink { l.fnWithValues(kv...) } out := *l + n := len(out.withValues) + out.withValues = append(out.withValues[:n:n], kv...) return &out } From 2665157dd6569fb0eec679fadef0947cbf573696 Mon Sep 17 00:00:00 2001 From: Tim Hockin Date: Tue, 5 Dec 2023 08:50:45 -0800 Subject: [PATCH 10/27] Add tests for context with slog --- context_slog_test.go | 66 ++++++++++++++++++++++++++++++++++++++++++++ context_test.go | 50 +++++++++++++++++++++++++++++++++ logr_test.go | 29 ------------------- 3 files changed, 116 insertions(+), 29 deletions(-) create mode 100644 context_slog_test.go create mode 100644 context_test.go diff --git a/context_slog_test.go b/context_slog_test.go new file mode 100644 index 0000000..faf1596 --- /dev/null +++ b/context_slog_test.go @@ -0,0 +1,66 @@ +//go:build go1.21 +// +build go1.21 + +/* +Copyright 2021 The logr 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 logr + +import ( + "context" + "log/slog" + "os" + "testing" +) + +func TestContextWithSlog(t *testing.T) { + ctx := context.Background() + + if out := FromContextAsSlogLogger(ctx); out != nil { + t.Errorf("expected no logger, got %#v", out) + } + + // Write as slog... + slogger := slog.New(slog.NewJSONHandler(os.Stderr, nil)) + sctx := NewContextWithSlogLogger(ctx, slogger) + + // ...read as logr + if out, err := FromContext(sctx); err != nil { + t.Errorf("unexpected error: %v", err) + } else if _, ok := out.sink.(*slogSink); !ok { + t.Errorf("expected output to be type *logr.slogSink, got %T", out.sink) + } + + // ...read as slog + if out := FromContextAsSlogLogger(sctx); out == nil { + t.Errorf("expected a *slog.JSONHandler, got nil") + } else if _, ok := out.Handler().(*slog.JSONHandler); !ok { + t.Errorf("expected output to be type *slog.JSONHandler, got %T", out.Handler()) + } + + // Write as logr... + logger := Discard() + lctx := NewContext(ctx, logger) + + // ...read as slog + if out := FromContextAsSlogLogger(lctx); out == nil { + t.Errorf("expected a *log.slogHandler, got nil") + } else if _, ok := out.Handler().(*slogHandler); !ok { + t.Errorf("expected output to be type *logr.slogHandler, got %T", out.Handler()) + } + + // ...read as logr is covered in the non-slog test +} diff --git a/context_test.go b/context_test.go new file mode 100644 index 0000000..b026a44 --- /dev/null +++ b/context_test.go @@ -0,0 +1,50 @@ +/* +Copyright 2021 The logr 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 logr + +import ( + "context" + "testing" +) + +func TestContext(t *testing.T) { + ctx := context.Background() + + if out, err := FromContext(ctx); err == nil { + t.Errorf("expected error, got %#v", out) + } else if _, ok := err.(notFoundError); !ok { + t.Errorf("expected a notFoundError, got %#v", err) + } + + out := FromContextOrDiscard(ctx) + if out.sink != nil { + t.Errorf("expected a nil sink, got %#v", out) + } + + sink := &testLogSink{} + logger := New(sink) + lctx := NewContext(ctx, logger) + if out, err := FromContext(lctx); err != nil { + t.Errorf("unexpected error: %v", err) + } else if p, _ := out.sink.(*testLogSink); p != sink { + t.Errorf("expected output to be the same as input, got in=%p, out=%p", sink, p) + } + out = FromContextOrDiscard(lctx) + if p, _ := out.sink.(*testLogSink); p != sink { + t.Errorf("expected output to be the same as input, got in=%p, out=%p", sink, p) + } +} diff --git a/logr_test.go b/logr_test.go index 3899013..354f038 100644 --- a/logr_test.go +++ b/logr_test.go @@ -17,7 +17,6 @@ limitations under the License. package logr import ( - "context" "errors" "fmt" "reflect" @@ -414,34 +413,6 @@ func TestWithCallDepthIncremental(t *testing.T) { } } -func TestContext(t *testing.T) { - ctx := context.TODO() - - if out, err := FromContext(ctx); err == nil { - t.Errorf("expected error, got %#v", out) - } else if _, ok := err.(notFoundError); !ok { - t.Errorf("expected a notFoundError, got %#v", err) - } - - out := FromContextOrDiscard(ctx) - if out.sink != nil { - t.Errorf("expected a nil sink, got %#v", out) - } - - sink := &testLogSink{} - logger := New(sink) - lctx := NewContext(ctx, logger) - if out, err := FromContext(lctx); err != nil { - t.Errorf("unexpected error: %v", err) - } else if p, _ := out.sink.(*testLogSink); p != sink { - t.Errorf("expected output to be the same as input, got in=%p, out=%p", sink, p) - } - out = FromContextOrDiscard(lctx) - if p, _ := out.sink.(*testLogSink); p != sink { - t.Errorf("expected output to be the same as input, got in=%p, out=%p", sink, p) - } -} - func TestIsZero(t *testing.T) { var l Logger if !l.IsZero() { From b01bad7e9f0e829c62fe17bb07ae22fd233141ab Mon Sep 17 00:00:00 2001 From: Tim Hockin Date: Thu, 7 Dec 2023 11:52:13 -0800 Subject: [PATCH 11/27] sloghandler: unnamed groups should be inlined This is part of a larger cleanup, but is a distinct bugfix. --- sloghandler.go | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/sloghandler.go b/sloghandler.go index 7d13002..2bbc4f5 100644 --- a/sloghandler.go +++ b/sloghandler.go @@ -127,6 +127,10 @@ func (l *slogHandler) WithGroup(name string) slog.Handler { if l.sink == nil { return l } + if name == "" { + // slog says to inline empty groups + return l + } copy := *l if l.slogSink != nil { copy.slogSink = l.slogSink.WithGroup(name) From cdb930d465eb98cee2fbb28ba1fe1ccfa4d1008c Mon Sep 17 00:00:00 2001 From: Tim Hockin Date: Tue, 5 Dec 2023 09:09:51 -0800 Subject: [PATCH 12/27] Minor cleanups in slogr_test (readability) --- slogr_test.go | 25 ++++++++++++++----------- 1 file changed, 14 insertions(+), 11 deletions(-) diff --git a/slogr_test.go b/slogr_test.go index fff6fb5..cb5a339 100644 --- a/slogr_test.go +++ b/slogr_test.go @@ -93,6 +93,10 @@ func TestWithCallDepth(t *testing.T) { var buffer bytes.Buffer logger := logr.FromSlogHandler(slog.NewTextHandler(&buffer, &debugWithCaller)) + logHelper := func(logger logr.Logger) { + logger.WithCallDepth(1).Info("hello") + } + logHelper(logger) _, file, line, _ := runtime.Caller(0) expectedSource := fmt.Sprintf("%s:%d", path.Base(file), line-1) @@ -102,10 +106,6 @@ func TestWithCallDepth(t *testing.T) { } } -func logHelper(logger logr.Logger) { - logger.WithCallDepth(1).Info("hello") -} - func TestJSONHandler(t *testing.T) { testSlog(t, func(buffer *bytes.Buffer) logr.Logger { handler := slog.NewJSONHandler(buffer, nil) @@ -141,10 +141,11 @@ func (s testSlogSink) WithGroup(name string) logr.SlogSink { } func TestFuncrHandler(t *testing.T) { - testSlog(t, func(buffer *bytes.Buffer) logr.Logger { - logger := funcr.NewJSON(func(obj string) { + fn := func(buffer *bytes.Buffer) logr.Logger { + printfn := func(obj string) { fmt.Fprintln(buffer, obj) - }, funcr.Options{ + } + opts := funcr.Options{ LogTimestamp: true, Verbosity: 10, RenderBuiltinsHook: func(kvList []any) []any { @@ -161,9 +162,10 @@ func TestFuncrHandler(t *testing.T) { } return mappedKVList }, - }) - return logger - }, + } + return funcr.NewJSON(printfn, opts) + } + exceptions := []string{ "a Handler should ignore a zero Record.Time", // Time is generated by sink. "a Handler should handle Group attributes", // funcr doesn't. "a Handler should inline the Attrs of a group with an empty key", // funcr doesn't know about groups. @@ -171,7 +173,8 @@ func TestFuncrHandler(t *testing.T) { "a Handler should handle the WithGroup method", // logHandler does by prefixing keys, which is not what the test expects. "a Handler should handle multiple WithGroup and WithAttr calls", // Same. "a Handler should call Resolve on attribute values in groups", // funcr doesn't do that and slogHandler can't do it for it. - ) + } + testSlog(t, fn, exceptions...) } func testSlog(t *testing.T, createLogger func(buffer *bytes.Buffer) logr.Logger, exceptions ...string) { From d95f9b6c6749a0c4e417ed5821463f6b5caefc3e Mon Sep 17 00:00:00 2001 From: Tim Hockin Date: Mon, 4 Dec 2023 09:18:06 -0800 Subject: [PATCH 13/27] Get rid of testSlogSink --- slogr_test.go | 44 ++++++++------------------------------------ 1 file changed, 8 insertions(+), 36 deletions(-) diff --git a/slogr_test.go b/slogr_test.go index cb5a339..4594456 100644 --- a/slogr_test.go +++ b/slogr_test.go @@ -21,7 +21,6 @@ package logr_test import ( "bytes" - "context" "encoding/json" "errors" "fmt" @@ -107,41 +106,14 @@ func TestWithCallDepth(t *testing.T) { } func TestJSONHandler(t *testing.T) { - testSlog(t, func(buffer *bytes.Buffer) logr.Logger { - handler := slog.NewJSONHandler(buffer, nil) - sink := testSlogSink{handler: handler} - return logr.New(sink) + // This proves that slogSink passes slog's own tests. + testSlog(t, func(buffer *bytes.Buffer) slog.Handler { + return slog.NewJSONHandler(buffer, nil) }) } -var _ logr.LogSink = testSlogSink{} -var _ logr.SlogSink = testSlogSink{} - -// testSlogSink is only used through slog and thus doesn't need to implement the -// normal LogSink methods. -type testSlogSink struct { - handler slog.Handler -} - -func (s testSlogSink) Init(logr.RuntimeInfo) {} -func (s testSlogSink) Enabled(int) bool { return true } -func (s testSlogSink) Error(error, string, ...interface{}) {} -func (s testSlogSink) Info(int, string, ...interface{}) {} -func (s testSlogSink) WithName(string) logr.LogSink { return s } -func (s testSlogSink) WithValues(...interface{}) logr.LogSink { return s } - -func (s testSlogSink) Handle(ctx context.Context, record slog.Record) error { - return s.handler.Handle(ctx, record) -} -func (s testSlogSink) WithAttrs(attrs []slog.Attr) logr.SlogSink { - return testSlogSink{handler: s.handler.WithAttrs(attrs)} -} -func (s testSlogSink) WithGroup(name string) logr.SlogSink { - return testSlogSink{handler: s.handler.WithGroup(name)} -} - func TestFuncrHandler(t *testing.T) { - fn := func(buffer *bytes.Buffer) logr.Logger { + fn := func(buffer *bytes.Buffer) slog.Handler { printfn := func(obj string) { fmt.Fprintln(buffer, obj) } @@ -163,7 +135,8 @@ func TestFuncrHandler(t *testing.T) { return mappedKVList }, } - return funcr.NewJSON(printfn, opts) + logger := funcr.NewJSON(printfn, opts) + return logr.ToSlogHandler(logger) } exceptions := []string{ "a Handler should ignore a zero Record.Time", // Time is generated by sink. @@ -177,10 +150,9 @@ func TestFuncrHandler(t *testing.T) { testSlog(t, fn, exceptions...) } -func testSlog(t *testing.T, createLogger func(buffer *bytes.Buffer) logr.Logger, exceptions ...string) { +func testSlog(t *testing.T, createHandler func(buffer *bytes.Buffer) slog.Handler, exceptions ...string) { var buffer bytes.Buffer - logger := createLogger(&buffer) - handler := logr.ToSlogHandler(logger) + handler := createHandler(&buffer) err := slogtest.TestHandler(handler, func() []map[string]any { var ms []map[string]any for _, line := range bytes.Split(buffer.Bytes(), []byte{'\n'}) { From 82218251a13a17855f02e5ee56f067bf993f3f4f Mon Sep 17 00:00:00 2001 From: Tim Hockin Date: Fri, 1 Dec 2023 14:27:34 -0800 Subject: [PATCH 14/27] Add SlogSink support to funcr Some of the testing done in slogr_test.go should probably be in funcr, but the test jig is just complex enough that I don't want to duplicate it in this commit. Later. --- funcr/example/main.go | 12 ++-- funcr/example/main_noslog.go | 29 ++++++++ funcr/example/main_slog.go | 42 +++++++++++ funcr/funcr.go | 134 ++++++++++++++++++++++++++++++----- funcr/slogsink.go | 105 +++++++++++++++++++++++++++ funcr/slogsink_test.go | 110 ++++++++++++++++++++++++++++ slogr_test.go | 16 ++--- 7 files changed, 416 insertions(+), 32 deletions(-) create mode 100644 funcr/example/main_noslog.go create mode 100644 funcr/example/main_slog.go create mode 100644 funcr/slogsink.go create mode 100644 funcr/slogsink_test.go diff --git a/funcr/example/main.go b/funcr/example/main.go index 8f8bbd8..a86ecd9 100644 --- a/funcr/example/main.go +++ b/funcr/example/main.go @@ -41,17 +41,21 @@ func helper2(log logr.Logger, msg string) { } func main() { - log := funcr.New( - func(pfx, args string) { fmt.Println(pfx, args) }, + // logr + log := funcr.NewJSON( + func(arg string) { fmt.Println(arg) }, funcr.Options{ LogCaller: funcr.All, LogTimestamp: true, Verbosity: 1, }) - example(log.WithValues("module", "example")) + logrExample(log.WithName("logr").WithValues("mode", "funcr")) + + // slog (if possible) + doSlog(log) } -func example(log logr.Logger) { +func logrExample(log logr.Logger) { log.Info("hello", "val1", 1, "val2", map[string]int{"k": 1}) log.V(1).Info("you should see this") log.V(1).V(1).Info("you should NOT see this") diff --git a/funcr/example/main_noslog.go b/funcr/example/main_noslog.go new file mode 100644 index 0000000..2329882 --- /dev/null +++ b/funcr/example/main_noslog.go @@ -0,0 +1,29 @@ +//go:build !go1.21 +// +build !go1.21 + +/* +Copyright 2023 The logr 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 main is an example of using funcr. +package main + +import ( + "github.com/go-logr/logr" +) + +func doSlog(log logr.Logger) { + log.Error(nil, "Sorry, slog is not supported on this version of Go") +} diff --git a/funcr/example/main_slog.go b/funcr/example/main_slog.go new file mode 100644 index 0000000..90f0419 --- /dev/null +++ b/funcr/example/main_slog.go @@ -0,0 +1,42 @@ +//go:build go1.21 +// +build go1.21 + +/* +Copyright 2023 The logr 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 main is an example of using funcr. +package main + +import ( + "log/slog" + + "github.com/go-logr/logr" +) + +func doSlog(log logr.Logger) { + slogger := slog.New(logr.ToSlogHandler(log.WithName("slog").WithValues("mode", "slog"))) + slogExample(slogger) +} + +func slogExample(log *slog.Logger) { + log.Warn("hello", "val1", 1, "val2", map[string]int{"k": 1}) + log.Info("you should see this") + log.Debug("you should NOT see this") + log.Error("uh oh", "trouble", true, "reasons", []float64{0.1, 0.11, 3.14}) + log.With("attr1", 1, "attr2", 2).Info("with attrs") + log.WithGroup("groupname").Info("with group", "slog2", false) + log.WithGroup("group1").With("attr1", 1).WithGroup("group2").With("attr2", 2).Info("msg", "arg", "val") +} diff --git a/funcr/funcr.go b/funcr/funcr.go index 12e5807..3c32080 100644 --- a/funcr/funcr.go +++ b/funcr/funcr.go @@ -227,12 +227,15 @@ func newFormatter(opts Options, outfmt outputFormat) Formatter { // implementation. It should be constructed with NewFormatter. Some of // its methods directly implement logr.LogSink. type Formatter struct { - outputFormat outputFormat - prefix string - values []any - valuesStr string - depth int - opts *Options + outputFormat outputFormat + prefix string + values []any + valuesStr string + parentValuesStr string + depth int + opts *Options + group string // for slog groups + groupDepth int } // outputFormat indicates which outputFormat to use. @@ -253,15 +256,17 @@ func (f Formatter) render(builtins, args []any) string { // Empirically bytes.Buffer is faster than strings.Builder for this. buf := bytes.NewBuffer(make([]byte, 0, 1024)) if f.outputFormat == outputJSON { - buf.WriteByte('{') + buf.WriteByte('{') // for the whole line } + vals := builtins if hook := f.opts.RenderBuiltinsHook; hook != nil { vals = hook(f.sanitize(vals)) } f.flatten(buf, vals, false, false) // keys are ours, no need to escape continuing := len(builtins) > 0 - if len(f.valuesStr) > 0 { + + if f.parentValuesStr != "" { if continuing { if f.outputFormat == outputJSON { buf.WriteByte(',') @@ -269,17 +274,60 @@ func (f Formatter) render(builtins, args []any) string { buf.WriteByte(' ') } } + buf.WriteString(f.parentValuesStr) continuing = true + } + + groupDepth := f.groupDepth + if f.group != "" { + if f.valuesStr != "" || len(args) != 0 { + if continuing { + if f.outputFormat == outputJSON { + buf.WriteByte(',') + } else { + buf.WriteByte(' ') + } + } + buf.WriteString(f.quoted(f.group, true)) // escape user-provided keys + if f.outputFormat == outputJSON { + buf.WriteByte(':') + } else { + buf.WriteByte('=') + } + buf.WriteByte('{') // for the group + continuing = false + } else { + // The group was empty + groupDepth-- + } + } + + if f.valuesStr != "" { + if continuing { + if f.outputFormat == outputJSON { + buf.WriteByte(',') + } else { + buf.WriteByte(' ') + } + } buf.WriteString(f.valuesStr) + continuing = true } + vals = args if hook := f.opts.RenderArgsHook; hook != nil { vals = hook(f.sanitize(vals)) } f.flatten(buf, vals, continuing, true) // escape user-provided keys + + for i := 0; i < groupDepth; i++ { + buf.WriteByte('}') // for the groups + } + if f.outputFormat == outputJSON { - buf.WriteByte('}') + buf.WriteByte('}') // for the whole line } + return buf.String() } @@ -316,14 +364,7 @@ func (f Formatter) flatten(buf *bytes.Buffer, kvList []any, continuing bool, esc } } - if escapeKeys { - buf.WriteString(prettyString(k)) - } else { - // this is faster - buf.WriteByte('"') - buf.WriteString(k) - buf.WriteByte('"') - } + buf.WriteString(f.quoted(k, escapeKeys)) if f.outputFormat == outputJSON { buf.WriteByte(':') } else { @@ -334,6 +375,14 @@ func (f Formatter) flatten(buf *bytes.Buffer, kvList []any, continuing bool, esc return kvList } +func (f Formatter) quoted(str string, escape bool) string { + if escape { + return prettyString(str) + } + // this is faster + return `"` + str + `"` +} + func (f Formatter) pretty(value any) string { return f.prettyWithFlags(value, 0, 0) } @@ -706,6 +755,57 @@ func (f Formatter) sanitize(kvList []any) []any { return kvList } +// startGroup opens a new group scope (basically a sub-struct), which locks all +// the current saved values and starts them anew. This is needed to satisfy +// slog. +func (f *Formatter) startGroup(group string) { + // Unnamed groups are just inlined. + if group == "" { + return + } + + // Any saved values can no longer be changed. + buf := bytes.NewBuffer(make([]byte, 0, 1024)) + continuing := false + + if f.parentValuesStr != "" { + buf.WriteString(f.parentValuesStr) + continuing = true + } + + if f.group != "" && f.valuesStr != "" { + if continuing { + buf.WriteByte(',') + } + buf.WriteString(f.quoted(f.group, true)) // escape user-provided keys + if f.outputFormat == outputJSON { + buf.WriteByte(':') + } else { + buf.WriteByte('=') + } + buf.WriteByte('{') // for the group + continuing = false + } + + if f.valuesStr != "" { + if continuing { + buf.WriteByte(',') + } + buf.WriteString(f.valuesStr) + } + + // NOTE: We don't close the scope here - that's done later, when a log line + // is actually rendered (because we have N scopes to close). + + f.parentValuesStr = buf.String() + + // Start collecting new values. + f.group = group + f.groupDepth++ + f.valuesStr = "" + f.values = nil +} + // Init configures this Formatter from runtime info, such as the call depth // imposed by logr itself. // Note that this receiver is a pointer, so depth can be saved. diff --git a/funcr/slogsink.go b/funcr/slogsink.go new file mode 100644 index 0000000..7bd8476 --- /dev/null +++ b/funcr/slogsink.go @@ -0,0 +1,105 @@ +//go:build go1.21 +// +build go1.21 + +/* +Copyright 2023 The logr 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 funcr + +import ( + "context" + "log/slog" + + "github.com/go-logr/logr" +) + +var _ logr.SlogSink = &fnlogger{} + +const extraSlogSinkDepth = 3 // 2 for slog, 1 for SlogSink + +func (l fnlogger) Handle(_ context.Context, record slog.Record) error { + kvList := make([]any, 0, 2*record.NumAttrs()) + record.Attrs(func(attr slog.Attr) bool { + kvList = attrToKVs(attr, kvList) + return true + }) + + if record.Level >= slog.LevelError { + l.WithCallDepth(extraSlogSinkDepth).Error(nil, record.Message, kvList...) + } else { + level := l.levelFromSlog(record.Level) + l.WithCallDepth(extraSlogSinkDepth).Info(level, record.Message, kvList...) + } + return nil +} + +func (l fnlogger) WithAttrs(attrs []slog.Attr) logr.SlogSink { + kvList := make([]any, 0, 2*len(attrs)) + for _, attr := range attrs { + kvList = attrToKVs(attr, kvList) + } + l.AddValues(kvList) + return &l +} + +func (l fnlogger) WithGroup(name string) logr.SlogSink { + l.startGroup(name) + return &l +} + +// attrToKVs appends a slog.Attr to a logr-style kvList. It handle slog Groups +// and other details of slog. +func attrToKVs(attr slog.Attr, kvList []any) []any { + attrVal := attr.Value.Resolve() + if attrVal.Kind() == slog.KindGroup { + groupVal := attrVal.Group() + grpKVs := make([]any, 0, 2*len(groupVal)) + for _, attr := range groupVal { + grpKVs = attrToKVs(attr, grpKVs) + } + if attr.Key == "" { + // slog says we have to inline these + kvList = append(kvList, grpKVs...) + } else { + kvList = append(kvList, attr.Key, PseudoStruct(grpKVs)) + } + } else if attr.Key != "" { + kvList = append(kvList, attr.Key, attrVal.Any()) + } + + return kvList +} + +// levelFromSlog adjusts the level by the logger's verbosity and negates it. +// It ensures that the result is >= 0. This is necessary because the result is +// passed to a LogSink and that API did not historically document whether +// levels could be negative or what that meant. +// +// Some example usage: +// +// logrV0 := getMyLogger() +// logrV2 := logrV0.V(2) +// slogV2 := slog.New(logr.ToSlogHandler(logrV2)) +// slogV2.Debug("msg") // =~ logrV2.V(4) =~ logrV0.V(6) +// slogV2.Info("msg") // =~ logrV2.V(0) =~ logrV0.V(2) +// slogv2.Warn("msg") // =~ logrV2.V(-4) =~ logrV0.V(0) +func (l fnlogger) levelFromSlog(level slog.Level) int { + result := -level + if result < 0 { + result = 0 // because LogSink doesn't expect negative V levels + } + return int(result) +} diff --git a/funcr/slogsink_test.go b/funcr/slogsink_test.go new file mode 100644 index 0000000..eb8d8a7 --- /dev/null +++ b/funcr/slogsink_test.go @@ -0,0 +1,110 @@ +//go:build go1.21 +// +build go1.21 + +/* +Copyright 2021 The logr 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 funcr + +import ( + "fmt" + "log/slog" + "path/filepath" + "runtime" + "testing" + + "github.com/go-logr/logr" +) + +func TestSlogSink(t *testing.T) { + testCases := []struct { + name string + withAttrs []any + withGroup string + args []any + expect string + }{{ + name: "just msg", + args: makeKV(), + expect: `{"logger":"","level":0,"msg":"msg"}`, + }, { + name: "primitives", + args: makeKV("int", 1, "str", "ABC", "bool", true), + expect: `{"logger":"","level":0,"msg":"msg","int":1,"str":"ABC","bool":true}`, + }, { + name: "with attrs", + withAttrs: makeKV("attrInt", 1, "attrStr", "ABC", "attrBool", true), + args: makeKV("int", 2), + expect: `{"logger":"","level":0,"msg":"msg","attrInt":1,"attrStr":"ABC","attrBool":true,"int":2}`, + }, { + name: "with group", + withGroup: "groupname", + args: makeKV("int", 1, "str", "ABC", "bool", true), + expect: `{"logger":"","level":0,"msg":"msg","groupname":{"int":1,"str":"ABC","bool":true}}`, + }, { + name: "with attrs and group", + withAttrs: makeKV("attrInt", 1, "attrStr", "ABC"), + withGroup: "groupname", + args: makeKV("int", 3, "bool", true), + expect: `{"logger":"","level":0,"msg":"msg","attrInt":1,"attrStr":"ABC","groupname":{"int":3,"bool":true}}`, + }} + + for _, tc := range testCases { + t.Run(tc.name, func(t *testing.T) { + capt := &capture{} + logger := logr.New(newSink(capt.Func, NewFormatterJSON(Options{}))) + slogger := slog.New(logr.ToSlogHandler(logger)) + if len(tc.withAttrs) > 0 { + slogger = slogger.With(tc.withAttrs...) + } + if tc.withGroup != "" { + slogger = slogger.WithGroup(tc.withGroup) + } + slogger.Info("msg", tc.args...) + if capt.log != tc.expect { + t.Errorf("\nexpected %q\n got %q", tc.expect, capt.log) + } + }) + } +} + +func TestSlogSinkNestedGroups(t *testing.T) { + capt := &capture{} + logger := logr.New(newSink(capt.Func, NewFormatterJSON(Options{}))) + slogger := slog.New(logr.ToSlogHandler(logger)) + slogger = slogger.With("out", 0) + slogger = slogger.WithGroup("g1").With("mid1", 1) + slogger = slogger.WithGroup("g2").With("mid2", 2) + slogger = slogger.WithGroup("g3").With("in", 3) + slogger.Info("msg", "k", "v") + + expect := `{"logger":"","level":0,"msg":"msg","out":0,"g1":{"mid1":1,"g2":{"mid2":2,"g3":{"in":3,"k":"v"}}}}` + if capt.log != expect { + t.Errorf("\nexpected %q\n got %q", expect, capt.log) + } +} + +func TestSlogSinkWithCaller(t *testing.T) { + capt := &capture{} + logger := logr.New(newSink(capt.Func, NewFormatterJSON(Options{LogCaller: All}))) + slogger := slog.New(logr.ToSlogHandler(logger)) + slogger.Error("msg", "int", 1) + _, file, line, _ := runtime.Caller(0) + expect := fmt.Sprintf(`{"logger":"","caller":{"file":%q,"line":%d},"msg":"msg","error":null,"int":1}`, filepath.Base(file), line-1) + if capt.log != expect { + t.Errorf("\nexpected %q\n got %q", expect, capt.log) + } +} diff --git a/slogr_test.go b/slogr_test.go index 4594456..7e5bfe7 100644 --- a/slogr_test.go +++ b/slogr_test.go @@ -82,7 +82,7 @@ func ExampleToSlogHandler() { // Output: // "level"=0 "msg"="hello world" // "msg"="ignore me" "error"=null "err"="fake error" - // "level"=0 "msg"="with values and group" "x"=1 "y"=2 "group.str"="abc" + // "level"=0 "msg"="with values and group" "x"=1 "y"=2 "group"={"str"="abc"} // "level"=4 "msg"="info message reduced to debug level" } @@ -139,13 +139,7 @@ func TestFuncrHandler(t *testing.T) { return logr.ToSlogHandler(logger) } exceptions := []string{ - "a Handler should ignore a zero Record.Time", // Time is generated by sink. - "a Handler should handle Group attributes", // funcr doesn't. - "a Handler should inline the Attrs of a group with an empty key", // funcr doesn't know about groups. - "a Handler should not output groups for an empty Record", // Relies on WithGroup. Text may change, see https://go.dev/cl/516155 - "a Handler should handle the WithGroup method", // logHandler does by prefixing keys, which is not what the test expects. - "a Handler should handle multiple WithGroup and WithAttr calls", // Same. - "a Handler should call Resolve on attribute values in groups", // funcr doesn't do that and slogHandler can't do it for it. + "a Handler should ignore a zero Record.Time", // Time is generated by sink. } testSlog(t, fn, exceptions...) } @@ -161,7 +155,7 @@ func testSlog(t *testing.T, createHandler func(buffer *bytes.Buffer) slog.Handle } var m map[string]any if err := json.Unmarshal(line, &m); err != nil { - t.Fatal(err) + t.Errorf("%v: %q", err, string(line)) } ms = append(ms, m) } @@ -172,10 +166,10 @@ func testSlog(t *testing.T, createHandler func(buffer *bytes.Buffer) slog.Handle // See https://github.com/golang/go/issues/61758 t.Logf("Output:\n%s", buffer.String()) if err != nil { - if err, ok := err.(interface { + if unwrappable, ok := err.(interface { Unwrap() []error }); ok { - for _, err := range err.Unwrap() { + for _, err := range unwrappable.Unwrap() { if !containsOne(err.Error(), exceptions...) { t.Errorf("Unexpected error: %v", err) } From 955d2aac19b6527eeae45580d1f408ba95e934d6 Mon Sep 17 00:00:00 2001 From: Tim Hockin Date: Fri, 1 Dec 2023 15:37:28 -0800 Subject: [PATCH 15/27] funcr: Be consistent about commas This uncovered a bug where it would sometimes write to the input list, corrupting tests. --- example_marshaler_secret_test.go | 2 +- example_marshaler_test.go | 2 +- funcr/funcr.go | 46 +++++++++++++++++--------------- funcr/funcr_test.go | 30 ++++++++++----------- 4 files changed, 41 insertions(+), 39 deletions(-) diff --git a/example_marshaler_secret_test.go b/example_marshaler_secret_test.go index 39ac4a4..950a159 100644 --- a/example_marshaler_secret_test.go +++ b/example_marshaler_secret_test.go @@ -43,5 +43,5 @@ func ExampleMarshaler_secret() { secret := ComplexObjectRef{Namespace: "kube-system", Name: "some-secret", Secret: "do-not-log-me"} l.Info("simplified", "secret", secret) // Output: - // "level"=0 "msg"="simplified" "secret"={"Name":"some-secret","Namespace":"kube-system"} + // "level"=0 "msg"="simplified" "secret"={"Name":"some-secret" "Namespace":"kube-system"} } diff --git a/example_marshaler_test.go b/example_marshaler_test.go index f9cd00a..f93f48f 100644 --- a/example_marshaler_test.go +++ b/example_marshaler_test.go @@ -51,5 +51,5 @@ func ExampleMarshaler() { l.Info("as struct", "pod", pod) // Output: // "level"=0 "msg"="as string" "pod"="kube-system/some-pod" - // "level"=0 "msg"="as struct" "pod"={"name":"some-pod","namespace":"kube-system"} + // "level"=0 "msg"="as struct" "pod"={"name":"some-pod" "namespace":"kube-system"} } diff --git a/funcr/funcr.go b/funcr/funcr.go index 3c32080..80ee702 100644 --- a/funcr/funcr.go +++ b/funcr/funcr.go @@ -268,11 +268,7 @@ func (f Formatter) render(builtins, args []any) string { if f.parentValuesStr != "" { if continuing { - if f.outputFormat == outputJSON { - buf.WriteByte(',') - } else { - buf.WriteByte(' ') - } + buf.WriteByte(f.comma()) } buf.WriteString(f.parentValuesStr) continuing = true @@ -282,11 +278,7 @@ func (f Formatter) render(builtins, args []any) string { if f.group != "" { if f.valuesStr != "" || len(args) != 0 { if continuing { - if f.outputFormat == outputJSON { - buf.WriteByte(',') - } else { - buf.WriteByte(' ') - } + buf.WriteByte(f.comma()) } buf.WriteString(f.quoted(f.group, true)) // escape user-provided keys if f.outputFormat == outputJSON { @@ -304,11 +296,7 @@ func (f Formatter) render(builtins, args []any) string { if f.valuesStr != "" { if continuing { - if f.outputFormat == outputJSON { - buf.WriteByte(',') - } else { - buf.WriteByte(' ') - } + buf.WriteByte(f.comma()) } buf.WriteString(f.valuesStr) continuing = true @@ -346,9 +334,16 @@ func (f Formatter) flatten(buf *bytes.Buffer, kvList []any, continuing bool, esc if len(kvList)%2 != 0 { kvList = append(kvList, noValue) } + copied := false for i := 0; i < len(kvList); i += 2 { k, ok := kvList[i].(string) if !ok { + if !copied { + newList := make([]any, len(kvList)) + copy(newList, kvList) + kvList = newList + copied = true + } k = f.nonStringKey(kvList[i]) kvList[i] = k } @@ -356,7 +351,7 @@ func (f Formatter) flatten(buf *bytes.Buffer, kvList []any, continuing bool, esc if i > 0 || continuing { if f.outputFormat == outputJSON { - buf.WriteByte(',') + buf.WriteByte(f.comma()) } else { // In theory the format could be something we don't understand. In // practice, we control it, so it won't be. @@ -383,6 +378,13 @@ func (f Formatter) quoted(str string, escape bool) string { return `"` + str + `"` } +func (f Formatter) comma() byte { + if f.outputFormat == outputJSON { + return ',' + } + return ' ' +} + func (f Formatter) pretty(value any) string { return f.prettyWithFlags(value, 0, 0) } @@ -456,7 +458,7 @@ func (f Formatter) prettyWithFlags(value any, flags uint32, depth int) string { } for i := 0; i < len(v); i += 2 { if i > 0 { - buf.WriteByte(',') + buf.WriteByte(f.comma()) } k, _ := v[i].(string) // sanitize() above means no need to check success // arbitrary keys might need escaping @@ -530,7 +532,7 @@ func (f Formatter) prettyWithFlags(value any, flags uint32, depth int) string { continue } if printComma { - buf.WriteByte(',') + buf.WriteByte(f.comma()) } printComma = true // if we got here, we are rendering a field if fld.Anonymous && fld.Type.Kind() == reflect.Struct && name == "" { @@ -569,7 +571,7 @@ func (f Formatter) prettyWithFlags(value any, flags uint32, depth int) string { buf.WriteByte('[') for i := 0; i < v.Len(); i++ { if i > 0 { - buf.WriteByte(',') + buf.WriteByte(f.comma()) } e := v.Index(i) buf.WriteString(f.prettyWithFlags(e.Interface(), 0, depth+1)) @@ -583,7 +585,7 @@ func (f Formatter) prettyWithFlags(value any, flags uint32, depth int) string { i := 0 for it.Next() { if i > 0 { - buf.WriteByte(',') + buf.WriteByte(f.comma()) } // If a map key supports TextMarshaler, use it. keystr := "" @@ -775,7 +777,7 @@ func (f *Formatter) startGroup(group string) { if f.group != "" && f.valuesStr != "" { if continuing { - buf.WriteByte(',') + buf.WriteByte(f.comma()) } buf.WriteString(f.quoted(f.group, true)) // escape user-provided keys if f.outputFormat == outputJSON { @@ -789,7 +791,7 @@ func (f *Formatter) startGroup(group string) { if f.valuesStr != "" { if continuing { - buf.WriteByte(',') + buf.WriteByte(f.comma()) } buf.WriteString(f.valuesStr) } diff --git a/funcr/funcr_test.go b/funcr/funcr_test.go index b3a6f70..9073016 100644 --- a/funcr/funcr_test.go +++ b/funcr/funcr_test.go @@ -659,7 +659,7 @@ func TestPretty(t *testing.T) { exp: `{"[{\"S\":\"\\\"quoted\\\"\"},{\"S\":\"unquoted\"}]":1}`, }} - f := NewFormatter(Options{}) + f := NewFormatterJSON(Options{}) for i, tc := range cases { ours := f.pretty(tc.val) want := "" @@ -759,17 +759,17 @@ func TestRender(t *testing.T) { F1 string F2 int }{"arg", 789}, "val"), - expectKV: `""="val" ""="val" ""="val"`, + expectKV: `""="val" ""="val" ""="val"`, expectJSON: `{"":"val","":"val","":"val"}`, }, { name: "json rendering with json.RawMessage", args: makeKV("key", raw), - expectKV: `"key"={"message":[123,34,105,110,116,49,34,58,48,44,34,45,34,58,48,44,34,73,110,116,53,34,58,48,125]}`, + expectKV: `"key"={"message":[123 34 105 110 116 49 34 58 48 44 34 45 34 58 48 44 34 73 110 116 53 34 58 48 125]}`, expectJSON: `{"key":{"message":{"int1":0,"-":0,"Int5":0}}}`, }, { name: "byte array not json.RawMessage", args: makeKV("key", []byte{1, 2, 3, 4}), - expectKV: `"key"=[1,2,3,4]`, + expectKV: `"key"=[1 2 3 4]`, expectJSON: `{"key":[1,2,3,4]}`, }, { name: "json rendering with empty json.RawMessage", @@ -784,7 +784,7 @@ func TestRender(t *testing.T) { formatter.AddValues(tc.values) r := formatter.render(tc.builtins, tc.args) if r != expect { - t.Errorf("wrong output:\nexpected %v\n got %v", expect, r) + t.Errorf("wrong output:\nexpected %q\n got %q", expect, r) } } t.Run("KV", func(t *testing.T) { @@ -918,13 +918,13 @@ func TestInfoWithCaller(t *testing.T) { sink := newSink(capt.Func, NewFormatter(Options{LogCaller: All})) sink.Info(0, "msg") _, file, line, _ := runtime.Caller(0) - expect := fmt.Sprintf(`"caller"={"file":%q,"line":%d} "level"=0 "msg"="msg"`, filepath.Base(file), line-1) + expect := fmt.Sprintf(`"caller"={"file":%q "line":%d} "level"=0 "msg"="msg"`, filepath.Base(file), line-1) if capt.log != expect { t.Errorf("\nexpected %q\n got %q", expect, capt.log) } sink.Error(fmt.Errorf("error"), "msg") _, file, line, _ = runtime.Caller(0) - expect = fmt.Sprintf(`"caller"={"file":%q,"line":%d} "msg"="msg" "error"="error"`, filepath.Base(file), line-1) + expect = fmt.Sprintf(`"caller"={"file":%q "line":%d} "msg"="msg" "error"="error"`, filepath.Base(file), line-1) if capt.log != expect { t.Errorf("\nexpected %q\n got %q", expect, capt.log) } @@ -951,13 +951,13 @@ func TestInfoWithCaller(t *testing.T) { sink := newSink(capt.Func, NewFormatter(Options{LogCaller: All, LogCallerFunc: true})) sink.Info(0, "msg") _, file, line, _ := runtime.Caller(0) - expect := fmt.Sprintf(`"caller"={"file":%q,"line":%d,"function":%q} "level"=0 "msg"="msg"`, filepath.Base(file), line-1, thisFunc) + expect := fmt.Sprintf(`"caller"={"file":%q "line":%d "function":%q} "level"=0 "msg"="msg"`, filepath.Base(file), line-1, thisFunc) if capt.log != expect { t.Errorf("\nexpected %q\n got %q", expect, capt.log) } sink.Error(fmt.Errorf("error"), "msg") _, file, line, _ = runtime.Caller(0) - expect = fmt.Sprintf(`"caller"={"file":%q,"line":%d,"function":%q} "msg"="msg" "error"="error"`, filepath.Base(file), line-1, thisFunc) + expect = fmt.Sprintf(`"caller"={"file":%q "line":%d "function":%q} "msg"="msg" "error"="error"`, filepath.Base(file), line-1, thisFunc) if capt.log != expect { t.Errorf("\nexpected %q\n got %q", expect, capt.log) } @@ -984,7 +984,7 @@ func TestInfoWithCaller(t *testing.T) { sink := newSink(capt.Func, NewFormatter(Options{LogCaller: Info})) sink.Info(0, "msg") _, file, line, _ := runtime.Caller(0) - expect := fmt.Sprintf(`"caller"={"file":%q,"line":%d} "level"=0 "msg"="msg"`, filepath.Base(file), line-1) + expect := fmt.Sprintf(`"caller"={"file":%q "line":%d} "level"=0 "msg"="msg"`, filepath.Base(file), line-1) if capt.log != expect { t.Errorf("\nexpected %q\n got %q", expect, capt.log) } @@ -1004,7 +1004,7 @@ func TestInfoWithCaller(t *testing.T) { } sink.Error(fmt.Errorf("error"), "msg") _, file, line, _ := runtime.Caller(0) - expect = fmt.Sprintf(`"caller"={"file":%q,"line":%d} "msg"="msg" "error"="error"`, filepath.Base(file), line-1) + expect = fmt.Sprintf(`"caller"={"file":%q "line":%d} "msg"="msg" "error"="error"`, filepath.Base(file), line-1) if capt.log != expect { t.Errorf("\nexpected %q\n got %q", expect, capt.log) } @@ -1069,7 +1069,7 @@ func TestErrorWithCaller(t *testing.T) { sink := newSink(capt.Func, NewFormatter(Options{LogCaller: All})) sink.Error(fmt.Errorf("err"), "msg") _, file, line, _ := runtime.Caller(0) - expect := fmt.Sprintf(`"caller"={"file":%q,"line":%d} "msg"="msg" "error"="err"`, filepath.Base(file), line-1) + expect := fmt.Sprintf(`"caller"={"file":%q "line":%d} "msg"="msg" "error"="err"`, filepath.Base(file), line-1) if capt.log != expect { t.Errorf("\nexpected %q\n got %q", expect, capt.log) } @@ -1089,7 +1089,7 @@ func TestErrorWithCaller(t *testing.T) { sink := newSink(capt.Func, NewFormatter(Options{LogCaller: Error})) sink.Error(fmt.Errorf("err"), "msg") _, file, line, _ := runtime.Caller(0) - expect := fmt.Sprintf(`"caller"={"file":%q,"line":%d} "msg"="msg" "error"="err"`, filepath.Base(file), line-1) + expect := fmt.Sprintf(`"caller"={"file":%q "line":%d} "msg"="msg" "error"="err"`, filepath.Base(file), line-1) if capt.log != expect { t.Errorf("\nexpected %q\n got %q", expect, capt.log) } @@ -1326,7 +1326,7 @@ func TestInfoWithCallDepth(t *testing.T) { sink = dSink.WithCallDepth(1) sink.Info(0, "msg") _, file, line, _ := runtime.Caller(1) - expect := fmt.Sprintf(`"caller"={"file":%q,"line":%d} "level"=0 "msg"="msg"`, filepath.Base(file), line) + expect := fmt.Sprintf(`"caller"={"file":%q "line":%d} "level"=0 "msg"="msg"`, filepath.Base(file), line) if capt.log != expect { t.Errorf("\nexpected %q\n got %q", expect, capt.log) } @@ -1341,7 +1341,7 @@ func TestErrorWithCallDepth(t *testing.T) { sink = dSink.WithCallDepth(1) sink.Error(fmt.Errorf("err"), "msg") _, file, line, _ := runtime.Caller(1) - expect := fmt.Sprintf(`"caller"={"file":%q,"line":%d} "msg"="msg" "error"="err"`, filepath.Base(file), line) + expect := fmt.Sprintf(`"caller"={"file":%q "line":%d} "msg"="msg" "error"="err"`, filepath.Base(file), line) if capt.log != expect { t.Errorf("\nexpected %q\n got %q", expect, capt.log) } From 44c6ac8097838fd1d648e3eb3b8bd6f15fa61e24 Mon Sep 17 00:00:00 2001 From: Tim Hockin Date: Fri, 1 Dec 2023 15:45:06 -0800 Subject: [PATCH 16/27] funcr: Be consistent about colons --- example_marshaler_secret_test.go | 2 +- example_marshaler_test.go | 2 +- funcr/funcr.go | 31 +++++++++++++------------------ funcr/funcr_test.go | 28 ++++++++++++++-------------- 4 files changed, 29 insertions(+), 34 deletions(-) diff --git a/example_marshaler_secret_test.go b/example_marshaler_secret_test.go index 950a159..f57ecd7 100644 --- a/example_marshaler_secret_test.go +++ b/example_marshaler_secret_test.go @@ -43,5 +43,5 @@ func ExampleMarshaler_secret() { secret := ComplexObjectRef{Namespace: "kube-system", Name: "some-secret", Secret: "do-not-log-me"} l.Info("simplified", "secret", secret) // Output: - // "level"=0 "msg"="simplified" "secret"={"Name":"some-secret" "Namespace":"kube-system"} + // "level"=0 "msg"="simplified" "secret"={"Name"="some-secret" "Namespace"="kube-system"} } diff --git a/example_marshaler_test.go b/example_marshaler_test.go index f93f48f..6c52b34 100644 --- a/example_marshaler_test.go +++ b/example_marshaler_test.go @@ -51,5 +51,5 @@ func ExampleMarshaler() { l.Info("as struct", "pod", pod) // Output: // "level"=0 "msg"="as string" "pod"="kube-system/some-pod" - // "level"=0 "msg"="as struct" "pod"={"name":"some-pod" "namespace":"kube-system"} + // "level"=0 "msg"="as struct" "pod"={"name"="some-pod" "namespace"="kube-system"} } diff --git a/funcr/funcr.go b/funcr/funcr.go index 80ee702..99eac75 100644 --- a/funcr/funcr.go +++ b/funcr/funcr.go @@ -281,11 +281,7 @@ func (f Formatter) render(builtins, args []any) string { buf.WriteByte(f.comma()) } buf.WriteString(f.quoted(f.group, true)) // escape user-provided keys - if f.outputFormat == outputJSON { - buf.WriteByte(':') - } else { - buf.WriteByte('=') - } + buf.WriteByte(f.colon()) buf.WriteByte('{') // for the group continuing = false } else { @@ -360,11 +356,7 @@ func (f Formatter) flatten(buf *bytes.Buffer, kvList []any, continuing bool, esc } buf.WriteString(f.quoted(k, escapeKeys)) - if f.outputFormat == outputJSON { - buf.WriteByte(':') - } else { - buf.WriteByte('=') - } + buf.WriteByte(f.colon()) buf.WriteString(f.pretty(v)) } return kvList @@ -385,6 +377,13 @@ func (f Formatter) comma() byte { return ' ' } +func (f Formatter) colon() byte { + if f.outputFormat == outputJSON { + return ':' + } + return '=' +} + func (f Formatter) pretty(value any) string { return f.prettyWithFlags(value, 0, 0) } @@ -463,7 +462,7 @@ func (f Formatter) prettyWithFlags(value any, flags uint32, depth int) string { k, _ := v[i].(string) // sanitize() above means no need to check success // arbitrary keys might need escaping buf.WriteString(prettyString(k)) - buf.WriteByte(':') + buf.WriteByte(f.colon()) buf.WriteString(f.prettyWithFlags(v[i+1], 0, depth+1)) } if flags&flagRawStruct == 0 { @@ -546,7 +545,7 @@ func (f Formatter) prettyWithFlags(value any, flags uint32, depth int) string { buf.WriteByte('"') buf.WriteString(name) buf.WriteByte('"') - buf.WriteByte(':') + buf.WriteByte(f.colon()) buf.WriteString(f.prettyWithFlags(v.Field(i).Interface(), 0, depth+1)) } if flags&flagRawStruct == 0 { @@ -607,7 +606,7 @@ func (f Formatter) prettyWithFlags(value any, flags uint32, depth int) string { } } buf.WriteString(keystr) - buf.WriteByte(':') + buf.WriteByte(f.colon()) buf.WriteString(f.prettyWithFlags(it.Value().Interface(), 0, depth+1)) i++ } @@ -780,11 +779,7 @@ func (f *Formatter) startGroup(group string) { buf.WriteByte(f.comma()) } buf.WriteString(f.quoted(f.group, true)) // escape user-provided keys - if f.outputFormat == outputJSON { - buf.WriteByte(':') - } else { - buf.WriteByte('=') - } + buf.WriteByte(f.colon()) buf.WriteByte('{') // for the group continuing = false } diff --git a/funcr/funcr_test.go b/funcr/funcr_test.go index 9073016..6a5c39c 100644 --- a/funcr/funcr_test.go +++ b/funcr/funcr_test.go @@ -722,7 +722,7 @@ func TestRender(t *testing.T) { builtins: makeKV("int", PseudoStruct(makeKV("intsub", 1))), values: makeKV("str", PseudoStruct(makeKV("strsub", "2"))), args: makeKV("bool", PseudoStruct(makeKV("boolsub", true))), - expectKV: `"int"={"intsub":1} "str"={"strsub":"2"} "bool"={"boolsub":true}`, + expectKV: `"int"={"intsub"=1} "str"={"strsub"="2"} "bool"={"boolsub"=true}`, expectJSON: `{"int":{"intsub":1},"str":{"strsub":"2"},"bool":{"boolsub":true}}`, }, { name: "escapes", @@ -759,12 +759,12 @@ func TestRender(t *testing.T) { F1 string F2 int }{"arg", 789}, "val"), - expectKV: `""="val" ""="val" ""="val"`, + expectKV: `""="val" ""="val" ""="val"`, expectJSON: `{"":"val","":"val","":"val"}`, }, { name: "json rendering with json.RawMessage", args: makeKV("key", raw), - expectKV: `"key"={"message":[123 34 105 110 116 49 34 58 48 44 34 45 34 58 48 44 34 73 110 116 53 34 58 48 125]}`, + expectKV: `"key"={"message"=[123 34 105 110 116 49 34 58 48 44 34 45 34 58 48 44 34 73 110 116 53 34 58 48 125]}`, expectJSON: `{"key":{"message":{"int1":0,"-":0,"Int5":0}}}`, }, { name: "byte array not json.RawMessage", @@ -774,7 +774,7 @@ func TestRender(t *testing.T) { }, { name: "json rendering with empty json.RawMessage", args: makeKV("key", &Trawjson{}), - expectKV: `"key"={"message":[]}`, + expectKV: `"key"={"message"=[]}`, expectJSON: `{"key":{"message":null}}`, }} @@ -918,13 +918,13 @@ func TestInfoWithCaller(t *testing.T) { sink := newSink(capt.Func, NewFormatter(Options{LogCaller: All})) sink.Info(0, "msg") _, file, line, _ := runtime.Caller(0) - expect := fmt.Sprintf(`"caller"={"file":%q "line":%d} "level"=0 "msg"="msg"`, filepath.Base(file), line-1) + expect := fmt.Sprintf(`"caller"={"file"=%q "line"=%d} "level"=0 "msg"="msg"`, filepath.Base(file), line-1) if capt.log != expect { t.Errorf("\nexpected %q\n got %q", expect, capt.log) } sink.Error(fmt.Errorf("error"), "msg") _, file, line, _ = runtime.Caller(0) - expect = fmt.Sprintf(`"caller"={"file":%q "line":%d} "msg"="msg" "error"="error"`, filepath.Base(file), line-1) + expect = fmt.Sprintf(`"caller"={"file"=%q "line"=%d} "msg"="msg" "error"="error"`, filepath.Base(file), line-1) if capt.log != expect { t.Errorf("\nexpected %q\n got %q", expect, capt.log) } @@ -951,13 +951,13 @@ func TestInfoWithCaller(t *testing.T) { sink := newSink(capt.Func, NewFormatter(Options{LogCaller: All, LogCallerFunc: true})) sink.Info(0, "msg") _, file, line, _ := runtime.Caller(0) - expect := fmt.Sprintf(`"caller"={"file":%q "line":%d "function":%q} "level"=0 "msg"="msg"`, filepath.Base(file), line-1, thisFunc) + expect := fmt.Sprintf(`"caller"={"file"=%q "line"=%d "function"=%q} "level"=0 "msg"="msg"`, filepath.Base(file), line-1, thisFunc) if capt.log != expect { t.Errorf("\nexpected %q\n got %q", expect, capt.log) } sink.Error(fmt.Errorf("error"), "msg") _, file, line, _ = runtime.Caller(0) - expect = fmt.Sprintf(`"caller"={"file":%q "line":%d "function":%q} "msg"="msg" "error"="error"`, filepath.Base(file), line-1, thisFunc) + expect = fmt.Sprintf(`"caller"={"file"=%q "line"=%d "function"=%q} "msg"="msg" "error"="error"`, filepath.Base(file), line-1, thisFunc) if capt.log != expect { t.Errorf("\nexpected %q\n got %q", expect, capt.log) } @@ -984,7 +984,7 @@ func TestInfoWithCaller(t *testing.T) { sink := newSink(capt.Func, NewFormatter(Options{LogCaller: Info})) sink.Info(0, "msg") _, file, line, _ := runtime.Caller(0) - expect := fmt.Sprintf(`"caller"={"file":%q "line":%d} "level"=0 "msg"="msg"`, filepath.Base(file), line-1) + expect := fmt.Sprintf(`"caller"={"file"=%q "line"=%d} "level"=0 "msg"="msg"`, filepath.Base(file), line-1) if capt.log != expect { t.Errorf("\nexpected %q\n got %q", expect, capt.log) } @@ -1004,7 +1004,7 @@ func TestInfoWithCaller(t *testing.T) { } sink.Error(fmt.Errorf("error"), "msg") _, file, line, _ := runtime.Caller(0) - expect = fmt.Sprintf(`"caller"={"file":%q "line":%d} "msg"="msg" "error"="error"`, filepath.Base(file), line-1) + expect = fmt.Sprintf(`"caller"={"file"=%q "line"=%d} "msg"="msg" "error"="error"`, filepath.Base(file), line-1) if capt.log != expect { t.Errorf("\nexpected %q\n got %q", expect, capt.log) } @@ -1069,7 +1069,7 @@ func TestErrorWithCaller(t *testing.T) { sink := newSink(capt.Func, NewFormatter(Options{LogCaller: All})) sink.Error(fmt.Errorf("err"), "msg") _, file, line, _ := runtime.Caller(0) - expect := fmt.Sprintf(`"caller"={"file":%q "line":%d} "msg"="msg" "error"="err"`, filepath.Base(file), line-1) + expect := fmt.Sprintf(`"caller"={"file"=%q "line"=%d} "msg"="msg" "error"="err"`, filepath.Base(file), line-1) if capt.log != expect { t.Errorf("\nexpected %q\n got %q", expect, capt.log) } @@ -1089,7 +1089,7 @@ func TestErrorWithCaller(t *testing.T) { sink := newSink(capt.Func, NewFormatter(Options{LogCaller: Error})) sink.Error(fmt.Errorf("err"), "msg") _, file, line, _ := runtime.Caller(0) - expect := fmt.Sprintf(`"caller"={"file":%q "line":%d} "msg"="msg" "error"="err"`, filepath.Base(file), line-1) + expect := fmt.Sprintf(`"caller"={"file"=%q "line"=%d} "msg"="msg" "error"="err"`, filepath.Base(file), line-1) if capt.log != expect { t.Errorf("\nexpected %q\n got %q", expect, capt.log) } @@ -1326,7 +1326,7 @@ func TestInfoWithCallDepth(t *testing.T) { sink = dSink.WithCallDepth(1) sink.Info(0, "msg") _, file, line, _ := runtime.Caller(1) - expect := fmt.Sprintf(`"caller"={"file":%q "line":%d} "level"=0 "msg"="msg"`, filepath.Base(file), line) + expect := fmt.Sprintf(`"caller"={"file"=%q "line"=%d} "level"=0 "msg"="msg"`, filepath.Base(file), line) if capt.log != expect { t.Errorf("\nexpected %q\n got %q", expect, capt.log) } @@ -1341,7 +1341,7 @@ func TestErrorWithCallDepth(t *testing.T) { sink = dSink.WithCallDepth(1) sink.Error(fmt.Errorf("err"), "msg") _, file, line, _ := runtime.Caller(1) - expect := fmt.Sprintf(`"caller"={"file":%q "line":%d} "msg"="msg" "error"="err"`, filepath.Base(file), line) + expect := fmt.Sprintf(`"caller"={"file"=%q "line"=%d} "msg"="msg" "error"="err"`, filepath.Base(file), line) if capt.log != expect { t.Errorf("\nexpected %q\n got %q", expect, capt.log) } From b5e7d9ff4449c24a7dea3ba3a459fffcd402e7f6 Mon Sep 17 00:00:00 2001 From: Tim Hockin Date: Fri, 1 Dec 2023 15:47:58 -0800 Subject: [PATCH 17/27] funcr: Be consistent about quoted --- funcr/funcr.go | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/funcr/funcr.go b/funcr/funcr.go index 99eac75..668d37a 100644 --- a/funcr/funcr.go +++ b/funcr/funcr.go @@ -542,9 +542,7 @@ func (f Formatter) prettyWithFlags(value any, flags uint32, depth int) string { name = fld.Name } // field names can't contain characters which need escaping - buf.WriteByte('"') - buf.WriteString(name) - buf.WriteByte('"') + buf.WriteString(f.quoted(name, false)) buf.WriteByte(f.colon()) buf.WriteString(f.prettyWithFlags(v.Field(i).Interface(), 0, depth+1)) } From 83dbe72954711644230be300373d358dcc468194 Mon Sep 17 00:00:00 2001 From: Tim Hockin Date: Fri, 1 Dec 2023 21:14:51 -0800 Subject: [PATCH 18/27] Fix some lint --- .github/workflows/lint.yaml | 5 +++++ sloghandler.go | 22 +++++++++++----------- slogr_test.go | 3 ++- slogsink.go | 4 ++-- 4 files changed, 20 insertions(+), 14 deletions(-) diff --git a/.github/workflows/lint.yaml b/.github/workflows/lint.yaml index 80b51b5..1a4b7bd 100644 --- a/.github/workflows/lint.yaml +++ b/.github/workflows/lint.yaml @@ -11,6 +11,11 @@ jobs: steps: - name: Checkout code uses: actions/checkout@b4ffde65f46336ab88eb53be808477a3936bae11 # v4.1.1 + - name: Update Go + uses: actions/setup-go@v4 + with: + go-version: '>=1.21.0' + cache: false - name: Lint uses: golangci/golangci-lint-action@3a919529898de77ec3da873e3063ca4b10e7f5cc # v3.7.0 with: diff --git a/sloghandler.go b/sloghandler.go index 2bbc4f5..6bed3e1 100644 --- a/sloghandler.go +++ b/sloghandler.go @@ -52,7 +52,7 @@ func (l *slogHandler) GetLevel() slog.Level { return l.levelBias } -func (l *slogHandler) Enabled(ctx context.Context, level slog.Level) bool { +func (l *slogHandler) Enabled(_ context.Context, level slog.Level) bool { return l.sink != nil && (level >= slog.LevelError || l.sink.Enabled(l.levelFromSlog(level))) } @@ -107,10 +107,10 @@ func (l *slogHandler) WithAttrs(attrs []slog.Attr) slog.Handler { return l } - copy := *l + clone := *l if l.slogSink != nil { - copy.slogSink = l.slogSink.WithAttrs(attrs) - copy.sink = copy.slogSink + clone.slogSink = l.slogSink.WithAttrs(attrs) + clone.sink = clone.slogSink } else { kvList := make([]any, 0, 2*len(attrs)) for _, attr := range attrs { @@ -118,9 +118,9 @@ func (l *slogHandler) WithAttrs(attrs []slog.Attr) slog.Handler { kvList = append(kvList, l.addGroupPrefix(attr.Key), attr.Value.Resolve().Any()) } } - copy.sink = l.sink.WithValues(kvList...) + clone.sink = l.sink.WithValues(kvList...) } - return © + return &clone } func (l *slogHandler) WithGroup(name string) slog.Handler { @@ -131,14 +131,14 @@ func (l *slogHandler) WithGroup(name string) slog.Handler { // slog says to inline empty groups return l } - copy := *l + clone := *l if l.slogSink != nil { - copy.slogSink = l.slogSink.WithGroup(name) - copy.sink = copy.slogSink + clone.slogSink = l.slogSink.WithGroup(name) + clone.sink = clone.slogSink } else { - copy.groupPrefix = copy.addGroupPrefix(name) + clone.groupPrefix = clone.addGroupPrefix(name) } - return © + return &clone } func (l *slogHandler) addGroupPrefix(name string) string { diff --git a/slogr_test.go b/slogr_test.go index 7e5bfe7..cf37a7b 100644 --- a/slogr_test.go +++ b/slogr_test.go @@ -190,7 +190,8 @@ func containsOne(hay string, needles ...string) bool { return false } -func TestDiscard(t *testing.T) { +func TestDiscard(_ *testing.T) { + // Compile-test logger := slog.New(logr.ToSlogHandler(logr.Discard())) logger.WithGroup("foo").With("x", 1).Info("hello") } diff --git a/slogsink.go b/slogsink.go index 93fa4e5..4060fcb 100644 --- a/slogsink.go +++ b/slogsink.go @@ -91,12 +91,12 @@ func (l *slogSink) log(err error, msg string, level slog.Level, kvList ...interf record.AddAttrs(slog.Any(errKey, err)) } record.Add(kvList...) - l.handler.Handle(context.Background(), record) + _ = l.handler.Handle(context.Background(), record) } func (l slogSink) WithName(name string) LogSink { if l.name != "" { - l.name = l.name + "/" + l.name += "/" } l.name += name return &l From f5585311a81686e8303d95835b6da84978b71eff Mon Sep 17 00:00:00 2001 From: Tim Hockin Date: Mon, 4 Dec 2023 09:33:28 -0800 Subject: [PATCH 19/27] Put slog tests in a helper, move funcr test --- funcr/slogsink_test.go | 43 ++++++++++++++++ internal/testhelp/slog.go | 79 +++++++++++++++++++++++++++++ internal/testhelp/slog_test.go | 33 ++++++++++++ slogr_test.go | 93 +++------------------------------- 4 files changed, 161 insertions(+), 87 deletions(-) create mode 100644 internal/testhelp/slog.go create mode 100644 internal/testhelp/slog_test.go diff --git a/funcr/slogsink_test.go b/funcr/slogsink_test.go index eb8d8a7..209717e 100644 --- a/funcr/slogsink_test.go +++ b/funcr/slogsink_test.go @@ -20,6 +20,7 @@ limitations under the License. package funcr import ( + "bytes" "fmt" "log/slog" "path/filepath" @@ -27,6 +28,7 @@ import ( "testing" "github.com/go-logr/logr" + "github.com/go-logr/logr/internal/testhelp" ) func TestSlogSink(t *testing.T) { @@ -108,3 +110,44 @@ func TestSlogSinkWithCaller(t *testing.T) { t.Errorf("\nexpected %q\n got %q", expect, capt.log) } } + +func TestRunSlogTests(t *testing.T) { + fn := func(buffer *bytes.Buffer) slog.Handler { + printfn := func(obj string) { + fmt.Fprintln(buffer, obj) + } + opts := Options{ + LogTimestamp: true, + Verbosity: 10, + RenderBuiltinsHook: func(kvList []any) []any { + mappedKVList := make([]any, len(kvList)) + for i := 0; i < len(kvList); i += 2 { + key := kvList[i] + switch key { + case "ts": + mappedKVList[i] = "time" + default: + mappedKVList[i] = key + } + mappedKVList[i+1] = kvList[i+1] + } + return mappedKVList + }, + } + logger := NewJSON(printfn, opts) + return logr.ToSlogHandler(logger) + } + exceptions := []string{ + "a Handler should ignore a zero Record.Time", // Time is generated by sink. + } + testhelp.RunSlogTests(t, fn, exceptions...) +} + +func TestLogrSlogConversion(t *testing.T) { + f := New(func(prefix, args string) {}, Options{}) + f2 := logr.FromSlogHandler(logr.ToSlogHandler(f)) + if want, got := f, f2; got != want { + t.Helper() + t.Errorf("Expected %T %+v, got instead: %T %+v", want, want, got, got) + } +} diff --git a/internal/testhelp/slog.go b/internal/testhelp/slog.go new file mode 100644 index 0000000..dce6139 --- /dev/null +++ b/internal/testhelp/slog.go @@ -0,0 +1,79 @@ +//go:build go1.21 +// +build go1.21 + +/* +Copyright 2023 The logr 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 testhelp holds helper functions for the testing of logr and built-in +// implementations. +package testhelp + +import ( + "bytes" + "encoding/json" + "log/slog" + "strings" + "testing" + "testing/slogtest" +) + +// RunSlogTests runs slogtest.TestHandler on a given slog.Handler, which is +// expected to emit JSON into the provided buffer. +func RunSlogTests(t *testing.T, createHandler func(buffer *bytes.Buffer) slog.Handler, exceptions ...string) { + var buffer bytes.Buffer + handler := createHandler(&buffer) + err := slogtest.TestHandler(handler, func() []map[string]any { + var ms []map[string]any + for _, line := range bytes.Split(buffer.Bytes(), []byte{'\n'}) { + if len(line) == 0 { + continue + } + var m map[string]any + if err := json.Unmarshal(line, &m); err != nil { + t.Errorf("%v: %q", err, string(line)) + } + ms = append(ms, m) + } + return ms + }) + + // Correlating failures with individual test cases is hard with the current API. + // See https://github.com/golang/go/issues/61758 + t.Logf("Output:\n%s", buffer.String()) + if err != nil { + if unwrappable, ok := err.(interface { + Unwrap() []error + }); ok { + for _, err := range unwrappable.Unwrap() { + if !containsOne(err.Error(), exceptions...) { + t.Errorf("Unexpected error: %v", err) + } + } + } else { + // Shouldn't be reached, errors from errors.Join can be split up. + t.Errorf("Unexpected errors:\n%v", err) + } + } +} + +func containsOne(hay string, needles ...string) bool { + for _, needle := range needles { + if strings.Contains(hay, needle) { + return true + } + } + return false +} diff --git a/internal/testhelp/slog_test.go b/internal/testhelp/slog_test.go new file mode 100644 index 0000000..cdc7f61 --- /dev/null +++ b/internal/testhelp/slog_test.go @@ -0,0 +1,33 @@ +//go:build go1.21 +// +build go1.21 + +/* +Copyright 2023 The logr 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 testhelp + +import ( + "bytes" + "log/slog" + "testing" +) + +func TestRunSlogTestsOnSlogSink(t *testing.T) { + // This proves that RunSlogTests works. + RunSlogTests(t, func(buffer *bytes.Buffer) slog.Handler { + return slog.NewJSONHandler(buffer, nil) + }) +} diff --git a/slogr_test.go b/slogr_test.go index cf37a7b..83634d5 100644 --- a/slogr_test.go +++ b/slogr_test.go @@ -21,7 +21,6 @@ package logr_test import ( "bytes" - "encoding/json" "errors" "fmt" "io" @@ -31,10 +30,10 @@ import ( "runtime" "strings" "testing" - "testing/slogtest" "github.com/go-logr/logr" "github.com/go-logr/logr/funcr" + "github.com/go-logr/logr/internal/testhelp" ) var debugWithoutTime = &slog.HandlerOptions{ @@ -105,92 +104,16 @@ func TestWithCallDepth(t *testing.T) { } } -func TestJSONHandler(t *testing.T) { +func TestRunSlogTestsOnSlogSink(t *testing.T) { // This proves that slogSink passes slog's own tests. - testSlog(t, func(buffer *bytes.Buffer) slog.Handler { - return slog.NewJSONHandler(buffer, nil) - }) -} - -func TestFuncrHandler(t *testing.T) { - fn := func(buffer *bytes.Buffer) slog.Handler { - printfn := func(obj string) { - fmt.Fprintln(buffer, obj) - } - opts := funcr.Options{ - LogTimestamp: true, - Verbosity: 10, - RenderBuiltinsHook: func(kvList []any) []any { - mappedKVList := make([]any, len(kvList)) - for i := 0; i < len(kvList); i += 2 { - key := kvList[i] - switch key { - case "ts": - mappedKVList[i] = "time" - default: - mappedKVList[i] = key - } - mappedKVList[i+1] = kvList[i+1] - } - return mappedKVList - }, - } - logger := funcr.NewJSON(printfn, opts) + testhelp.RunSlogTests(t, func(buffer *bytes.Buffer) slog.Handler { + handler := slog.NewJSONHandler(buffer, nil) + logger := logr.FromSlogHandler(handler) return logr.ToSlogHandler(logger) - } - exceptions := []string{ - "a Handler should ignore a zero Record.Time", // Time is generated by sink. - } - testSlog(t, fn, exceptions...) -} - -func testSlog(t *testing.T, createHandler func(buffer *bytes.Buffer) slog.Handler, exceptions ...string) { - var buffer bytes.Buffer - handler := createHandler(&buffer) - err := slogtest.TestHandler(handler, func() []map[string]any { - var ms []map[string]any - for _, line := range bytes.Split(buffer.Bytes(), []byte{'\n'}) { - if len(line) == 0 { - continue - } - var m map[string]any - if err := json.Unmarshal(line, &m); err != nil { - t.Errorf("%v: %q", err, string(line)) - } - ms = append(ms, m) - } - return ms }) - - // Correlating failures with individual test cases is hard with the current API. - // See https://github.com/golang/go/issues/61758 - t.Logf("Output:\n%s", buffer.String()) - if err != nil { - if unwrappable, ok := err.(interface { - Unwrap() []error - }); ok { - for _, err := range unwrappable.Unwrap() { - if !containsOne(err.Error(), exceptions...) { - t.Errorf("Unexpected error: %v", err) - } - } - } else { - // Shouldn't be reached, errors from errors.Join can be split up. - t.Errorf("Unexpected errors:\n%v", err) - } - } } -func containsOne(hay string, needles ...string) bool { - for _, needle := range needles { - if strings.Contains(hay, needle) { - return true - } - } - return false -} - -func TestDiscard(_ *testing.T) { +func TestSlogSinkOnDiscard(_ *testing.T) { // Compile-test logger := slog.New(logr.ToSlogHandler(logr.Discard())) logger.WithGroup("foo").With("x", 1).Info("hello") @@ -205,10 +128,6 @@ func TestConversion(t *testing.T) { e2 := logr.FromSlogHandler(logr.ToSlogHandler(e)) expectEqual(t, e, e2) - f := funcr.New(func(prefix, args string) {}, funcr.Options{}) - f2 := logr.FromSlogHandler(logr.ToSlogHandler(f)) - expectEqual(t, f, f2) - text := slog.NewTextHandler(io.Discard, nil) text2 := logr.ToSlogHandler(logr.FromSlogHandler(text)) expectEqual(t, text, text2) From 64328772921a64a598eb222e2b0d0b9317651521 Mon Sep 17 00:00:00 2001 From: Tim Hockin Date: Mon, 4 Dec 2023 13:55:35 -0800 Subject: [PATCH 20/27] Add benchmarks for slogSink --- benchmark/benchmark_slog_test.go | 142 +++++++++++++++++++++++++++++++ benchmark/benchmark_test.go | 8 ++ 2 files changed, 150 insertions(+) create mode 100644 benchmark/benchmark_slog_test.go diff --git a/benchmark/benchmark_slog_test.go b/benchmark/benchmark_slog_test.go new file mode 100644 index 0000000..6f115fd --- /dev/null +++ b/benchmark/benchmark_slog_test.go @@ -0,0 +1,142 @@ +//go:build go1.21 +// +build go1.21 + +/* +Copyright 2021 The logr 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 logr + +import ( + "log/slog" + "os" + "testing" + + "github.com/go-logr/logr" +) + +// +// slogSink wrapper of discard +// + +func BenchmarkSlogSinkLogInfoOneArg(b *testing.B) { + var log logr.Logger = logr.FromSlogHandler(logr.ToSlogHandler(logr.Discard())) + doInfoOneArg(b, log) +} + +func BenchmarkSlogSinkLogInfoSeveralArgs(b *testing.B) { + var log logr.Logger = logr.FromSlogHandler(logr.ToSlogHandler(logr.Discard())) + doInfoSeveralArgs(b, log) +} + +func BenchmarkSlogSinkLogInfoWithValues(b *testing.B) { + var log logr.Logger = logr.FromSlogHandler(logr.ToSlogHandler(logr.Discard())) + doInfoWithValues(b, log) +} + +func BenchmarkSlogSinkLogV0Info(b *testing.B) { + var log logr.Logger = logr.FromSlogHandler(logr.ToSlogHandler(logr.Discard())) + doV0Info(b, log) +} + +func BenchmarkSlogSinkLogV9Info(b *testing.B) { + var log logr.Logger = logr.FromSlogHandler(logr.ToSlogHandler(logr.Discard())) + doV9Info(b, log) +} + +func BenchmarkSlogSinkLogError(b *testing.B) { + var log logr.Logger = logr.FromSlogHandler(logr.ToSlogHandler(logr.Discard())) + doError(b, log) +} + +func BenchmarkSlogSinkWithValues(b *testing.B) { + var log logr.Logger = logr.FromSlogHandler(logr.ToSlogHandler(logr.Discard())) + doWithValues(b, log) +} + +func BenchmarkSlogSinkWithName(b *testing.B) { + var log logr.Logger = logr.FromSlogHandler(logr.ToSlogHandler(logr.Discard())) + doWithName(b, log) +} + +// +// slogSink wrapper of slog's JSONHandler, for comparison +// + +func makeSlogJSONLogger() logr.Logger { + devnull, _ := os.Open("/dev/null") + handler := slog.NewJSONHandler(devnull, nil) + return logr.FromSlogHandler(handler) +} + +func BenchmarkSlogJSONLogInfoOneArg(b *testing.B) { + var log logr.Logger = makeSlogJSONLogger() + doInfoOneArg(b, log) +} + +func BenchmarkSlogJSONLogInfoSeveralArgs(b *testing.B) { + var log logr.Logger = makeSlogJSONLogger() + doInfoSeveralArgs(b, log) +} + +func BenchmarkSlogJSONLogInfoWithValues(b *testing.B) { + var log logr.Logger = makeSlogJSONLogger() + doInfoWithValues(b, log) +} + +func BenchmarkSlogJSONLogV0Info(b *testing.B) { + var log logr.Logger = makeSlogJSONLogger() + doV0Info(b, log) +} + +func BenchmarkSlogJSONLogV9Info(b *testing.B) { + var log logr.Logger = makeSlogJSONLogger() + doV9Info(b, log) +} + +func BenchmarkSlogJSONLogError(b *testing.B) { + var log logr.Logger = makeSlogJSONLogger() + doError(b, log) +} + +func BenchmarkSlogJSONLogWithValues(b *testing.B) { + var log logr.Logger = makeSlogJSONLogger() + doWithValues(b, log) +} + +func BenchmarkSlogJSONWithName(b *testing.B) { + var log logr.Logger = makeSlogJSONLogger() + doWithName(b, log) +} + +func BenchmarkSlogJSONWithCallDepth(b *testing.B) { + var log logr.Logger = makeSlogJSONLogger() + doWithCallDepth(b, log) +} + +func BenchmarkSlogJSONLogInfoStringerValue(b *testing.B) { + var log logr.Logger = makeSlogJSONLogger() + doStringerValue(b, log) +} + +func BenchmarkSlogJSONLogInfoErrorValue(b *testing.B) { + var log logr.Logger = makeSlogJSONLogger() + doErrorValue(b, log) +} + +func BenchmarkSlogJSONLogInfoMarshalerValue(b *testing.B) { + var log logr.Logger = makeSlogJSONLogger() + doMarshalerValue(b, log) +} diff --git a/benchmark/benchmark_test.go b/benchmark/benchmark_test.go index 090e3ce..35c7dd0 100644 --- a/benchmark/benchmark_test.go +++ b/benchmark/benchmark_test.go @@ -141,6 +141,10 @@ func doMarshalerValue(b *testing.B, log logr.Logger) { } } +// +// discard +// + func BenchmarkDiscardLogInfoOneArg(b *testing.B) { var log logr.Logger = logr.Discard() doInfoOneArg(b, log) @@ -181,6 +185,10 @@ func BenchmarkDiscardWithName(b *testing.B) { doWithName(b, log) } +// +// funcr +// + func noopKV(_, _ string) {} func noopJSON(_ string) {} From b228ba8636d02f868be6802747693a8489b182e2 Mon Sep 17 00:00:00 2001 From: Tim Hockin Date: Tue, 5 Dec 2023 10:22:26 -0800 Subject: [PATCH 21/27] Break examples to new file --- example_slogr_test.go | 79 +++++++++++++++++++++++++++++++++++++++++++ slogr_test.go | 67 +++++++----------------------------- 2 files changed, 91 insertions(+), 55 deletions(-) create mode 100644 example_slogr_test.go diff --git a/example_slogr_test.go b/example_slogr_test.go new file mode 100644 index 0000000..6f568f9 --- /dev/null +++ b/example_slogr_test.go @@ -0,0 +1,79 @@ +//go:build go1.21 +// +build go1.21 + +/* +Copyright 2023 The logr 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 logr_test + +import ( + "errors" + "fmt" + "log/slog" + "os" + + "github.com/go-logr/logr" + "github.com/go-logr/logr/funcr" +) + +var debugWithoutTime = &slog.HandlerOptions{ + ReplaceAttr: func(groups []string, a slog.Attr) slog.Attr { + if a.Key == "time" { + return slog.Attr{} + } + return a + }, + Level: slog.LevelDebug, +} + +func ExampleFromSlogHandler() { + logrLogger := logr.FromSlogHandler(slog.NewTextHandler(os.Stdout, debugWithoutTime)) + + logrLogger.Info("hello world") + logrLogger.Error(errors.New("fake error"), "ignore me") + logrLogger.WithValues("x", 1, "y", 2).WithValues("str", "abc").WithName("foo").WithName("bar").V(4).Info("with values, verbosity and name") + + // Output: + // level=INFO msg="hello world" + // level=ERROR msg="ignore me" err="fake error" + // level=DEBUG msg="with values, verbosity and name" x=1 y=2 str=abc logger=foo/bar +} + +func ExampleToSlogHandler() { + funcrLogger := funcr.New(func(prefix, args string) { + if prefix != "" { + fmt.Fprintln(os.Stdout, prefix, args) + } else { + fmt.Fprintln(os.Stdout, args) + } + }, funcr.Options{ + Verbosity: 10, + }) + + slogLogger := slog.New(logr.ToSlogHandler(funcrLogger)) + slogLogger.Info("hello world") + slogLogger.Error("ignore me", "err", errors.New("fake error")) + slogLogger.With("x", 1, "y", 2).WithGroup("group").With("str", "abc").Warn("with values and group") + + slogLogger = slog.New(logr.ToSlogHandler(funcrLogger.V(int(-slog.LevelDebug)))) + slogLogger.Info("info message reduced to debug level") + + // Output: + // "level"=0 "msg"="hello world" + // "msg"="ignore me" "error"=null "err"="fake error" + // "level"=0 "msg"="with values and group" "x"=1 "y"=2 "group"={"str"="abc"} + // "level"=4 "msg"="info message reduced to debug level" +} diff --git a/slogr_test.go b/slogr_test.go index 83634d5..332c7e9 100644 --- a/slogr_test.go +++ b/slogr_test.go @@ -17,22 +17,18 @@ See the License for the specific language governing permissions and limitations under the License. */ -package logr_test +package logr import ( "bytes" - "errors" "fmt" "io" "log/slog" - "os" "path" "runtime" "strings" "testing" - "github.com/go-logr/logr" - "github.com/go-logr/logr/funcr" "github.com/go-logr/logr/internal/testhelp" ) @@ -46,52 +42,13 @@ var debugWithoutTime = &slog.HandlerOptions{ Level: slog.LevelDebug, } -func ExampleFromSlogHandler() { - logrLogger := logr.FromSlogHandler(slog.NewTextHandler(os.Stdout, debugWithoutTime)) - - logrLogger.Info("hello world") - logrLogger.Error(errors.New("fake error"), "ignore me") - logrLogger.WithValues("x", 1, "y", 2).WithValues("str", "abc").WithName("foo").WithName("bar").V(4).Info("with values, verbosity and name") - - // Output: - // level=INFO msg="hello world" - // level=ERROR msg="ignore me" err="fake error" - // level=DEBUG msg="with values, verbosity and name" x=1 y=2 str=abc logger=foo/bar -} - -func ExampleToSlogHandler() { - funcrLogger := funcr.New(func(prefix, args string) { - if prefix != "" { - fmt.Fprintln(os.Stdout, prefix, args) - } else { - fmt.Fprintln(os.Stdout, args) - } - }, funcr.Options{ - Verbosity: 10, - }) - - slogLogger := slog.New(logr.ToSlogHandler(funcrLogger)) - slogLogger.Info("hello world") - slogLogger.Error("ignore me", "err", errors.New("fake error")) - slogLogger.With("x", 1, "y", 2).WithGroup("group").With("str", "abc").Warn("with values and group") - - slogLogger = slog.New(logr.ToSlogHandler(funcrLogger.V(int(-slog.LevelDebug)))) - slogLogger.Info("info message reduced to debug level") - - // Output: - // "level"=0 "msg"="hello world" - // "msg"="ignore me" "error"=null "err"="fake error" - // "level"=0 "msg"="with values and group" "x"=1 "y"=2 "group"={"str"="abc"} - // "level"=4 "msg"="info message reduced to debug level" -} - func TestWithCallDepth(t *testing.T) { debugWithCaller := *debugWithoutTime debugWithCaller.AddSource = true var buffer bytes.Buffer - logger := logr.FromSlogHandler(slog.NewTextHandler(&buffer, &debugWithCaller)) + logger := FromSlogHandler(slog.NewTextHandler(&buffer, &debugWithCaller)) - logHelper := func(logger logr.Logger) { + logHelper := func(logger Logger) { logger.WithCallDepth(1).Info("hello") } @@ -108,31 +65,31 @@ func TestRunSlogTestsOnSlogSink(t *testing.T) { // This proves that slogSink passes slog's own tests. testhelp.RunSlogTests(t, func(buffer *bytes.Buffer) slog.Handler { handler := slog.NewJSONHandler(buffer, nil) - logger := logr.FromSlogHandler(handler) - return logr.ToSlogHandler(logger) + logger := FromSlogHandler(handler) + return ToSlogHandler(logger) }) } func TestSlogSinkOnDiscard(_ *testing.T) { // Compile-test - logger := slog.New(logr.ToSlogHandler(logr.Discard())) + logger := slog.New(ToSlogHandler(Discard())) logger.WithGroup("foo").With("x", 1).Info("hello") } func TestConversion(t *testing.T) { - d := logr.Discard() - d2 := logr.FromSlogHandler(logr.ToSlogHandler(d)) + d := Discard() + d2 := FromSlogHandler(ToSlogHandler(d)) expectEqual(t, d, d2) - e := logr.Logger{} - e2 := logr.FromSlogHandler(logr.ToSlogHandler(e)) + e := Logger{} + e2 := FromSlogHandler(ToSlogHandler(e)) expectEqual(t, e, e2) text := slog.NewTextHandler(io.Discard, nil) - text2 := logr.ToSlogHandler(logr.FromSlogHandler(text)) + text2 := ToSlogHandler(FromSlogHandler(text)) expectEqual(t, text, text2) - text3 := logr.ToSlogHandler(logr.FromSlogHandler(text).V(1)) + text3 := ToSlogHandler(FromSlogHandler(text).V(1)) if handler, ok := text3.(interface { GetLevel() slog.Level }); ok { From 98ee9d96bccd21c2ddb6cbe144aed9022119b233 Mon Sep 17 00:00:00 2001 From: Tim Hockin Date: Wed, 6 Dec 2023 09:33:32 -0800 Subject: [PATCH 22/27] Clean up slog testing and restore coverage --- logr_noslog_test.go | 23 ----- logr_slog_test.go | 218 ----------------------------------------- logr_test.go | 79 --------------- sloghandler.go | 41 ++++++-- slogr_test.go | 93 +++++++++++++++++- testimpls_slog_test.go | 140 ++++++++++++++++++++++++++ testimpls_test.go | 92 +++++++++++++++++ 7 files changed, 352 insertions(+), 334 deletions(-) delete mode 100644 logr_noslog_test.go delete mode 100644 logr_slog_test.go create mode 100644 testimpls_slog_test.go create mode 100644 testimpls_test.go diff --git a/logr_noslog_test.go b/logr_noslog_test.go deleted file mode 100644 index c449810..0000000 --- a/logr_noslog_test.go +++ /dev/null @@ -1,23 +0,0 @@ -//go:build !go1.21 -// +build !go1.21 - -/* -Copyright 2023 The logr 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 logr - -//nolint:unused -type testSlogSink struct{} diff --git a/logr_slog_test.go b/logr_slog_test.go deleted file mode 100644 index 7712235..0000000 --- a/logr_slog_test.go +++ /dev/null @@ -1,218 +0,0 @@ -//go:build go1.21 -// +build go1.21 - -/* -Copyright 2023 The logr 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 logr - -import ( - "bytes" - "context" - "log/slog" - "testing" - "time" -) - -var _ SlogSink = &testLogSink{} - -// testSlogSink gets embedded in testLogSink to add slog-specific fields -// which are only available when slog is supported by Go. -type testSlogSink struct { - attrs []slog.Attr - groups []string - - fnHandle func(l *testLogSink, ctx context.Context, record slog.Record) - fnWithAttrs func(l *testLogSink, attrs []slog.Attr) - fnWithGroup func(l *testLogSink, name string) -} - -func (l *testLogSink) Handle(ctx context.Context, record slog.Record) error { - if l.fnHandle != nil { - l.fnHandle(l, ctx, record) - } - return nil -} - -func (l *testLogSink) WithAttrs(attrs []slog.Attr) SlogSink { - if l.fnWithAttrs != nil { - l.fnWithAttrs(l, attrs) - } - out := *l - n := len(out.attrs) - out.attrs = append(out.attrs[:n:n], attrs...) - return &out -} - -func (l *testLogSink) WithGroup(name string) SlogSink { - if l.fnWithGroup != nil { - l.fnWithGroup(l, name) - } - out := *l - n := len(out.groups) - out.groups = append(out.groups[:n:n], name) - return &out -} - -func withAttrs(record slog.Record, attrs ...slog.Attr) slog.Record { - record = record.Clone() - record.AddAttrs(attrs...) - return record -} - -func toJSON(record slog.Record) string { - var buffer bytes.Buffer - record.Time = time.Time{} - handler := slog.NewJSONHandler(&buffer, nil) - if err := handler.Handle(context.Background(), record); err != nil { - return err.Error() - } - return buffer.String() -} - -func TestToSlogHandler(t *testing.T) { - lvlThreshold := 0 - actualCalledHandle := 0 - var actualRecord slog.Record - - sink := &testLogSink{} - logger := New(sink) - - sink.fnEnabled = func(lvl int) bool { - return lvl <= lvlThreshold - } - - sink.fnHandle = func(l *testLogSink, ctx context.Context, record slog.Record) { - actualCalledHandle++ - - // Combine attributes from sink and call. Ordering of WithValues and WithAttrs - // is wrong, but good enough for test cases. - var values slog.Record - values.Add(l.withValues...) - var attrs []any - add := func(attr slog.Attr) bool { - attrs = append(attrs, attr) - return true - } - values.Attrs(add) - record.Attrs(add) - for _, attr := range l.attrs { - attrs = append(attrs, attr) - } - - // Wrap them in groups - not quite correct for WithValues that - // follows WithGroup, but good enough for test cases. - for i := len(l.groups) - 1; i >= 0; i-- { - attrs = []any{slog.Group(l.groups[i], attrs...)} - } - - actualRecord = slog.Record{ - Level: record.Level, - Message: record.Message, - } - actualRecord.Add(attrs...) - } - - verify := func(t *testing.T, expectedRecord slog.Record) { - actual := toJSON(actualRecord) - expected := toJSON(expectedRecord) - if expected != actual { - t.Errorf("JSON dump did not match, expected:\n%s\nGot:\n%s\n", expected, actual) - } - } - - reset := func() { - lvlThreshold = 0 - actualCalledHandle = 0 - actualRecord = slog.Record{} - } - - testcases := map[string]struct { - run func() - expectedRecord slog.Record - }{ - "simple": { - func() { slog.New(ToSlogHandler(logger)).Info("simple") }, - slog.Record{Message: "simple"}, - }, - - "disabled": { - func() { slog.New(ToSlogHandler(logger.V(1))).Info("") }, - slog.Record{}, - }, - - "enabled": { - func() { - lvlThreshold = 1 - slog.New(ToSlogHandler(logger.V(1))).Info("enabled") - }, - slog.Record{Level: -1, Message: "enabled"}, - }, - - "error": { - func() { slog.New(ToSlogHandler(logger.V(100))).Error("error") }, - slog.Record{Level: slog.LevelError, Message: "error"}, - }, - - "with-parameters": { - func() { slog.New(ToSlogHandler(logger)).Info("", "answer", 42, "foo", "bar") }, - withAttrs(slog.Record{}, slog.Int("answer", 42), slog.String("foo", "bar")), - }, - - "with-values": { - func() { slog.New(ToSlogHandler(logger.WithValues("answer", 42, "foo", "bar"))).Info("") }, - withAttrs(slog.Record{}, slog.Int("answer", 42), slog.String("foo", "bar")), - }, - - "with-group": { - func() { slog.New(ToSlogHandler(logger)).WithGroup("group").Info("", "answer", 42, "foo", "bar") }, - withAttrs(slog.Record{}, slog.Group("group", slog.Int("answer", 42), slog.String("foo", "bar"))), - }, - - "with-values-and-group": { - func() { - slog.New(ToSlogHandler(logger.WithValues("answer", 42, "foo", "bar"))).WithGroup("group").Info("") - }, - // Behavior of testLogSink is not quite correct here. - withAttrs(slog.Record{}, slog.Group("group", slog.Int("answer", 42), slog.String("foo", "bar"))), - }, - - "with-group-and-values": { - func() { - slog.New(ToSlogHandler(logger)).WithGroup("group").With("answer", 42, "foo", "bar").Info("") - }, - withAttrs(slog.Record{}, slog.Group("group", slog.Int("answer", 42), slog.String("foo", "bar"))), - }, - - "with-group-and-logr-values": { - func() { - slogLogger := slog.New(ToSlogHandler(logger)).WithGroup("group") - logrLogger := FromSlogHandler(slogLogger.Handler()).WithValues("answer", 42, "foo", "bar") - slogLogger = slog.New(ToSlogHandler(logrLogger)) - slogLogger.Info("") - }, - withAttrs(slog.Record{}, slog.Group("group", slog.Int("answer", 42), slog.String("foo", "bar"))), - }, - } - - for name, tc := range testcases { - t.Run(name, func(t *testing.T) { - tc.run() - verify(t, tc.expectedRecord) - reset() - }) - } -} diff --git a/logr_test.go b/logr_test.go index 354f038..dc33cc2 100644 --- a/logr_test.go +++ b/logr_test.go @@ -24,85 +24,6 @@ import ( "testing" ) -// testLogSink is a Logger just for testing that calls optional hooks on each method. -type testLogSink struct { - fnInit func(ri RuntimeInfo) - fnEnabled func(lvl int) bool - fnInfo func(lvl int, msg string, kv ...any) - fnError func(err error, msg string, kv ...any) - fnWithValues func(kv ...any) - fnWithName func(name string) - - withValues []any - - // testSlogSink contains some additional fields if (and only if) slog is supported by Go. - // See logr_slog_test.go. - //nolint:unused // Only unused with Go < 1.21. - testSlogSink -} - -var _ LogSink = &testLogSink{} - -func (l *testLogSink) Init(ri RuntimeInfo) { - if l.fnInit != nil { - l.fnInit(ri) - } -} - -func (l *testLogSink) Enabled(lvl int) bool { - if l.fnEnabled != nil { - return l.fnEnabled(lvl) - } - return false -} - -func (l *testLogSink) Info(lvl int, msg string, kv ...any) { - if l.fnInfo != nil { - l.fnInfo(lvl, msg, kv...) - } -} - -func (l *testLogSink) Error(err error, msg string, kv ...any) { - if l.fnError != nil { - l.fnError(err, msg, kv...) - } -} - -func (l *testLogSink) WithValues(kv ...any) LogSink { - if l.fnWithValues != nil { - l.fnWithValues(kv...) - } - out := *l - n := len(out.withValues) - out.withValues = append(out.withValues[:n:n], kv...) - return &out -} - -func (l *testLogSink) WithName(name string) LogSink { - if l.fnWithName != nil { - l.fnWithName(name) - } - out := *l - return &out -} - -type testCallDepthLogSink struct { - testLogSink - callDepth int - fnWithCallDepth func(depth int) -} - -var _ CallDepthLogSink = &testCallDepthLogSink{} - -func (l *testCallDepthLogSink) WithCallDepth(depth int) LogSink { - if l.fnWithCallDepth != nil { - l.fnWithCallDepth(depth) - } - out := *l - out.callDepth += depth - return &out -} - func TestNew(t *testing.T) { calledInit := 0 diff --git a/sloghandler.go b/sloghandler.go index 6bed3e1..82d1ba4 100644 --- a/sloghandler.go +++ b/sloghandler.go @@ -70,9 +70,7 @@ func (l *slogHandler) Handle(ctx context.Context, record slog.Record) error { kvList := make([]any, 0, 2*record.NumAttrs()) record.Attrs(func(attr slog.Attr) bool { - if attr.Key != "" { - kvList = append(kvList, l.addGroupPrefix(attr.Key), attr.Value.Resolve().Any()) - } + kvList = attrToKVs(attr, l.groupPrefix, kvList) return true }) if record.Level >= slog.LevelError { @@ -114,9 +112,7 @@ func (l *slogHandler) WithAttrs(attrs []slog.Attr) slog.Handler { } else { kvList := make([]any, 0, 2*len(attrs)) for _, attr := range attrs { - if attr.Key != "" { - kvList = append(kvList, l.addGroupPrefix(attr.Key), attr.Value.Resolve().Any()) - } + kvList = attrToKVs(attr, l.groupPrefix, kvList) } clone.sink = l.sink.WithValues(kvList...) } @@ -136,16 +132,41 @@ func (l *slogHandler) WithGroup(name string) slog.Handler { clone.slogSink = l.slogSink.WithGroup(name) clone.sink = clone.slogSink } else { - clone.groupPrefix = clone.addGroupPrefix(name) + clone.groupPrefix = addPrefix(clone.groupPrefix, name) } return &clone } -func (l *slogHandler) addGroupPrefix(name string) string { - if l.groupPrefix == "" { +// attrToKVs appends a slog.Attr to a logr-style kvList. It handle slog Groups +// and other details of slog. +func attrToKVs(attr slog.Attr, groupPrefix string, kvList []any) []any { + attrVal := attr.Value.Resolve() + if attrVal.Kind() == slog.KindGroup { + groupVal := attrVal.Group() + grpKVs := make([]any, 0, 2*len(groupVal)) + prefix := groupPrefix + if attr.Key != "" { + prefix = addPrefix(groupPrefix, attr.Key) + } + for _, attr := range groupVal { + grpKVs = attrToKVs(attr, prefix, grpKVs) + } + kvList = append(kvList, grpKVs...) + } else if attr.Key != "" { + kvList = append(kvList, addPrefix(groupPrefix, attr.Key), attrVal.Any()) + } + + return kvList +} + +func addPrefix(prefix, name string) string { + if prefix == "" { return name } - return l.groupPrefix + groupSeparator + name + if name == "" { + return prefix + } + return prefix + groupSeparator + name } // levelFromSlog adjusts the level by the logger's verbosity and negates it. diff --git a/slogr_test.go b/slogr_test.go index 332c7e9..2b00a50 100644 --- a/slogr_test.go +++ b/slogr_test.go @@ -24,6 +24,7 @@ import ( "fmt" "io" "log/slog" + "os" "path" "runtime" "strings" @@ -32,6 +33,58 @@ import ( "github.com/go-logr/logr/internal/testhelp" ) +func TestToSlogHandler(t *testing.T) { + t.Run("from simple Logger", func(t *testing.T) { + logger := New(&testLogSink{}) + handler := ToSlogHandler(logger) + if _, ok := handler.(*slogHandler); !ok { + t.Errorf("expected type *slogHandler, got %T", handler) + } + }) + + t.Run("from slog-enabled Logger", func(t *testing.T) { + logger := New(&testSlogSink{}) + handler := ToSlogHandler(logger) + if _, ok := handler.(*slogHandler); !ok { + t.Errorf("expected type *slogHandler, got %T", handler) + } + }) + + t.Run("from slogSink Logger", func(t *testing.T) { + logger := New(&slogSink{handler: slog.NewJSONHandler(os.Stderr, nil)}) + handler := ToSlogHandler(logger) + if _, ok := handler.(*slog.JSONHandler); !ok { + t.Errorf("expected type *slog.JSONHandler, got %T", handler) + } + }) +} + +func TestFromSlogHandler(t *testing.T) { + t.Run("from slog Handler", func(t *testing.T) { + handler := slog.NewJSONHandler(os.Stderr, nil) + logger := FromSlogHandler(handler) + if _, ok := logger.sink.(*slogSink); !ok { + t.Errorf("expected type *slogSink, got %T", logger.sink) + } + }) + + t.Run("from simple slogHandler Handler", func(t *testing.T) { + handler := &slogHandler{sink: &testLogSink{}} + logger := FromSlogHandler(handler) + if _, ok := logger.sink.(*testLogSink); !ok { + t.Errorf("expected type *testSlogSink, got %T", logger.sink) + } + }) + + t.Run("from discard slogHandler Handler", func(t *testing.T) { + handler := &slogHandler{} + logger := FromSlogHandler(handler) + if logger != Discard() { + t.Errorf("expected type *testSlogSink, got %T", logger.sink) + } + }) +} + var debugWithoutTime = &slog.HandlerOptions{ ReplaceAttr: func(groups []string, a slog.Attr) slog.Attr { if a.Key == "time" { @@ -61,13 +114,45 @@ func TestWithCallDepth(t *testing.T) { } } -func TestRunSlogTestsOnSlogSink(t *testing.T) { - // This proves that slogSink passes slog's own tests. +func TestRunSlogTestsOnSlogHandlerLogSink(t *testing.T) { + // This proves that slogHandler passes slog's own tests when given a + // non-SlogSink LogSink. + exceptions := []string{ + // logr sinks handle time themselves + "a Handler should ignore a zero Record.Time", + // slogHandler does not do groups "properly", so these all fail with + // "missing group". It's looking for `"G":{"a":"b"}` and getting + // `"G.a": "b"`. + "a Handler should handle Group attributes", + "a Handler should handle the WithGroup method", + "a Handler should handle multiple WithGroup and WithAttr calls", + "a Handler should not output groups for an empty Record", + "a Handler should call Resolve on attribute values in groups", + "a Handler should call Resolve on attribute values in groups from WithAttrs", + } testhelp.RunSlogTests(t, func(buffer *bytes.Buffer) slog.Handler { + // We want a known-good Logger that emits JSON but is not a slogHandler + // or SlogSink (since those get special treatment). We can trust that + // the slog JSONHandler works. handler := slog.NewJSONHandler(buffer, nil) - logger := FromSlogHandler(handler) + sink := &passthruLogSink{handler: handler} + logger := New(sink) return ToSlogHandler(logger) - }) + }, exceptions...) +} + +func TestRunSlogTestsOnSlogHandlerSlogSink(t *testing.T) { + // This proves that slogHandler passes slog's own tests when given a + // SlogSink. + exceptions := []string{} + testhelp.RunSlogTests(t, func(buffer *bytes.Buffer) slog.Handler { + // We want a known-good Logger that emits JSON and implements SlogSink, + // to cover those paths. We can trust that the slog JSONHandler works. + handler := slog.NewJSONHandler(buffer, nil) + sink := &passthruSlogSink{handler: handler} + logger := New(sink) + return ToSlogHandler(logger) + }, exceptions...) } func TestSlogSinkOnDiscard(_ *testing.T) { diff --git a/testimpls_slog_test.go b/testimpls_slog_test.go new file mode 100644 index 0000000..5ae2690 --- /dev/null +++ b/testimpls_slog_test.go @@ -0,0 +1,140 @@ +//go:build go1.21 +// +build go1.21 + +/* +Copyright 2023 The logr 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 logr + +import ( + "context" + "log/slog" + "time" +) + +var _ SlogSink = &testSlogSink{} + +// testSlogSink is a trivial SlogSink implementation, just for testing, which +// calls (optional) hooks on each method. +type testSlogSink struct { + // embed a plain LogSink + testLogSink + + attrs []slog.Attr + groups []string + + fnHandle func(ss *testSlogSink, ctx context.Context, record slog.Record) + fnWithAttrs func(ss *testSlogSink, attrs []slog.Attr) + fnWithGroup func(ss *testSlogSink, name string) +} + +func (ss *testSlogSink) Handle(ctx context.Context, record slog.Record) error { + if ss.fnHandle != nil { + ss.fnHandle(ss, ctx, record) + } + return nil +} + +func (ss *testSlogSink) WithAttrs(attrs []slog.Attr) SlogSink { + if ss.fnWithAttrs != nil { + ss.fnWithAttrs(ss, attrs) + } + out := *ss + n := len(out.attrs) + out.attrs = append(out.attrs[:n:n], attrs...) + return &out +} + +func (ss *testSlogSink) WithGroup(name string) SlogSink { + if ss.fnWithGroup != nil { + ss.fnWithGroup(ss, name) + } + out := *ss + n := len(out.groups) + out.groups = append(out.groups[:n:n], name) + return &out +} + +// passthruLogSink is a trivial LogSink implementation, which implements the +// logr.LogSink methods in terms of a slog.Handler. +type passthruLogSink struct { + handler slog.Handler +} + +func (pl passthruLogSink) Init(RuntimeInfo) {} + +func (pl passthruLogSink) Enabled(int) bool { return true } + +func (pl passthruLogSink) Error(_ error, msg string, kvList ...interface{}) { + var record slog.Record + record.Message = msg + record.Level = slog.LevelError + record.Time = time.Now() + record.Add(kvList...) + _ = pl.handler.Handle(context.Background(), record) +} + +func (pl passthruLogSink) Info(_ int, msg string, kvList ...interface{}) { + var record slog.Record + record.Message = msg + record.Level = slog.LevelInfo + record.Time = time.Now() + record.Add(kvList...) + _ = pl.handler.Handle(context.Background(), record) +} + +func (pl passthruLogSink) WithName(string) LogSink { return &pl } + +func (pl passthruLogSink) WithValues(kvList ...interface{}) LogSink { + var values slog.Record + values.Add(kvList...) + var attrs []slog.Attr + add := func(attr slog.Attr) bool { + attrs = append(attrs, attr) + return true + } + values.Attrs(add) + + pl.handler = pl.handler.WithAttrs(attrs) + return &pl +} + +// passthruSlogSink is a trivial SlogSink implementation, which stubs out the +// logr.LogSink methods and passes Logr.SlogSink thru to a slog.Handler. +type passthruSlogSink struct { + handler slog.Handler +} + +func (ps passthruSlogSink) Init(RuntimeInfo) {} +func (ps passthruSlogSink) Enabled(int) bool { return true } +func (ps passthruSlogSink) Error(error, string, ...interface{}) {} +func (ps passthruSlogSink) Info(int, string, ...interface{}) {} +func (ps passthruSlogSink) WithName(string) LogSink { return &ps } +func (ps passthruSlogSink) WithValues(...interface{}) LogSink { return &ps } + +func (ps *passthruSlogSink) Handle(ctx context.Context, record slog.Record) error { + return ps.handler.Handle(ctx, record) +} + +func (ps passthruSlogSink) WithAttrs(attrs []slog.Attr) SlogSink { + ps.handler = ps.handler.WithAttrs(attrs) + return &ps +} + +func (ps passthruSlogSink) WithGroup(name string) SlogSink { + ps.handler = ps.handler.WithGroup(name) + return &ps +} diff --git a/testimpls_test.go b/testimpls_test.go new file mode 100644 index 0000000..08571db --- /dev/null +++ b/testimpls_test.go @@ -0,0 +1,92 @@ +/* +Copyright 2021 The logr 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 logr + +// testLogSink is a trivial LogSink implementation, just for testing, which +// calls (optional) hooks on each method. +type testLogSink struct { + fnInit func(ri RuntimeInfo) + fnEnabled func(lvl int) bool + fnInfo func(lvl int, msg string, kv ...any) + fnError func(err error, msg string, kv ...any) + fnWithValues func(kv ...any) + fnWithName func(name string) + + withValues []any +} + +var _ LogSink = &testLogSink{} + +func (ls *testLogSink) Init(ri RuntimeInfo) { + if ls.fnInit != nil { + ls.fnInit(ri) + } +} + +func (ls *testLogSink) Enabled(lvl int) bool { + if ls.fnEnabled != nil { + return ls.fnEnabled(lvl) + } + return false +} + +func (ls *testLogSink) Info(lvl int, msg string, kv ...any) { + if ls.fnInfo != nil { + ls.fnInfo(lvl, msg, kv...) + } +} + +func (ls *testLogSink) Error(err error, msg string, kv ...any) { + if ls.fnError != nil { + ls.fnError(err, msg, kv...) + } +} + +func (ls *testLogSink) WithValues(kv ...any) LogSink { + if ls.fnWithValues != nil { + ls.fnWithValues(kv...) + } + out := *ls + n := len(out.withValues) + out.withValues = append(out.withValues[:n:n], kv...) + return &out +} + +func (ls *testLogSink) WithName(name string) LogSink { + if ls.fnWithName != nil { + ls.fnWithName(name) + } + out := *ls + return &out +} + +type testCallDepthLogSink struct { + testLogSink + callDepth int + fnWithCallDepth func(depth int) +} + +var _ CallDepthLogSink = &testCallDepthLogSink{} + +func (ls *testCallDepthLogSink) WithCallDepth(depth int) LogSink { + if ls.fnWithCallDepth != nil { + ls.fnWithCallDepth(depth) + } + out := *ls + out.callDepth += depth + return &out +} From 2ad296ec40a3bbda65a372e58a27d566e2e05083 Mon Sep 17 00:00:00 2001 From: "dependabot[bot]" <49699333+dependabot[bot]@users.noreply.github.com> Date: Mon, 11 Dec 2023 01:01:14 +0000 Subject: [PATCH 23/27] build(deps): bump github/codeql-action from 2.22.8 to 2.22.9 Bumps [github/codeql-action](https://github.com/github/codeql-action) from 2.22.8 to 2.22.9. - [Release notes](https://github.com/github/codeql-action/releases) - [Changelog](https://github.com/github/codeql-action/blob/main/CHANGELOG.md) - [Commits](https://github.com/github/codeql-action/compare/407ffafae6a767df3e0230c3df91b6443ae8df75...c0d1daa7f7e14667747d73a7dbbe8c074bc8bfe2) --- updated-dependencies: - dependency-name: github/codeql-action dependency-type: direct:production update-type: version-update:semver-patch ... Signed-off-by: dependabot[bot] --- .github/workflows/scorecard.yml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.github/workflows/scorecard.yml b/.github/workflows/scorecard.yml index e3e8ec0..7292e82 100644 --- a/.github/workflows/scorecard.yml +++ b/.github/workflows/scorecard.yml @@ -59,6 +59,6 @@ jobs: # Upload the results to GitHub's code scanning dashboard. - name: "Upload to code-scanning" - uses: github/codeql-action/upload-sarif@407ffafae6a767df3e0230c3df91b6443ae8df75 # v2.22.8 + uses: github/codeql-action/upload-sarif@c0d1daa7f7e14667747d73a7dbbe8c074bc8bfe2 # v2.22.9 with: sarif_file: results.sarif From cf56c3b5da5a00eacf11e94616fe5dfe873bee52 Mon Sep 17 00:00:00 2001 From: "dependabot[bot]" <49699333+dependabot[bot]@users.noreply.github.com> Date: Mon, 11 Dec 2023 01:01:18 +0000 Subject: [PATCH 24/27] build(deps): bump actions/setup-go from 4 to 5 Bumps [actions/setup-go](https://github.com/actions/setup-go) from 4 to 5. - [Release notes](https://github.com/actions/setup-go/releases) - [Commits](https://github.com/actions/setup-go/compare/v4...v5) --- updated-dependencies: - dependency-name: actions/setup-go dependency-type: direct:production update-type: version-update:semver-major ... Signed-off-by: dependabot[bot] --- .github/workflows/apidiff.yaml | 2 +- .github/workflows/lint.yaml | 2 +- .github/workflows/tests.yaml | 2 +- 3 files changed, 3 insertions(+), 3 deletions(-) diff --git a/.github/workflows/apidiff.yaml b/.github/workflows/apidiff.yaml index 7002b22..a70414e 100644 --- a/.github/workflows/apidiff.yaml +++ b/.github/workflows/apidiff.yaml @@ -11,7 +11,7 @@ jobs: if: github.base_ref steps: - name: Install Go - uses: actions/setup-go@93397bea11091df50f3d7e59dc26a7711a8bcfbe # v4.1.0 + uses: actions/setup-go@0c52d547c9bc32b1aa3301fd7a9cb496313a4491 # v5.0.0 with: go-version: 1.20.x - name: Add GOBIN to PATH diff --git a/.github/workflows/lint.yaml b/.github/workflows/lint.yaml index 1a4b7bd..f178de7 100644 --- a/.github/workflows/lint.yaml +++ b/.github/workflows/lint.yaml @@ -12,7 +12,7 @@ jobs: - name: Checkout code uses: actions/checkout@b4ffde65f46336ab88eb53be808477a3936bae11 # v4.1.1 - name: Update Go - uses: actions/setup-go@v4 + uses: actions/setup-go@v5 with: go-version: '>=1.21.0' cache: false diff --git a/.github/workflows/tests.yaml b/.github/workflows/tests.yaml index add16a5..5719fdb 100644 --- a/.github/workflows/tests.yaml +++ b/.github/workflows/tests.yaml @@ -14,7 +14,7 @@ jobs: runs-on: ${{ matrix.platform }} steps: - name: Install Go - uses: actions/setup-go@93397bea11091df50f3d7e59dc26a7711a8bcfbe # v4.1.0 + uses: actions/setup-go@0c52d547c9bc32b1aa3301fd7a9cb496313a4491 # v5.0.0 with: go-version: ${{ matrix.version }} - name: Checkout code From e7f489a410309014c7d2ddc70800f2e3031a34f6 Mon Sep 17 00:00:00 2001 From: "dependabot[bot]" <49699333+dependabot[bot]@users.noreply.github.com> Date: Mon, 18 Dec 2023 00:14:04 +0000 Subject: [PATCH 25/27] build(deps): bump github/codeql-action from 2.22.9 to 3.22.11 Bumps [github/codeql-action](https://github.com/github/codeql-action) from 2.22.9 to 3.22.11. - [Release notes](https://github.com/github/codeql-action/releases) - [Changelog](https://github.com/github/codeql-action/blob/main/CHANGELOG.md) - [Commits](https://github.com/github/codeql-action/compare/c0d1daa7f7e14667747d73a7dbbe8c074bc8bfe2...b374143c1149a9115d881581d29b8390bbcbb59c) --- updated-dependencies: - dependency-name: github/codeql-action dependency-type: direct:production update-type: version-update:semver-major ... Signed-off-by: dependabot[bot] --- .github/workflows/scorecard.yml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.github/workflows/scorecard.yml b/.github/workflows/scorecard.yml index 7292e82..dfc4e17 100644 --- a/.github/workflows/scorecard.yml +++ b/.github/workflows/scorecard.yml @@ -59,6 +59,6 @@ jobs: # Upload the results to GitHub's code scanning dashboard. - name: "Upload to code-scanning" - uses: github/codeql-action/upload-sarif@c0d1daa7f7e14667747d73a7dbbe8c074bc8bfe2 # v2.22.9 + uses: github/codeql-action/upload-sarif@b374143c1149a9115d881581d29b8390bbcbb59c # v3.22.11 with: sarif_file: results.sarif From 177005d4eef9d394e2cb5702ab1c0dfb51ddef0f Mon Sep 17 00:00:00 2001 From: "dependabot[bot]" <49699333+dependabot[bot]@users.noreply.github.com> Date: Mon, 18 Dec 2023 00:14:09 +0000 Subject: [PATCH 26/27] build(deps): bump actions/upload-artifact from 3.1.3 to 4.0.0 Bumps [actions/upload-artifact](https://github.com/actions/upload-artifact) from 3.1.3 to 4.0.0. - [Release notes](https://github.com/actions/upload-artifact/releases) - [Commits](https://github.com/actions/upload-artifact/compare/a8a3f3ad30e3422c9c7b888a15615d19a852ae32...c7d193f32edcb7bfad88892161225aeda64e9392) --- updated-dependencies: - dependency-name: actions/upload-artifact dependency-type: direct:production update-type: version-update:semver-major ... Signed-off-by: dependabot[bot] --- .github/workflows/scorecard.yml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.github/workflows/scorecard.yml b/.github/workflows/scorecard.yml index dfc4e17..54f7616 100644 --- a/.github/workflows/scorecard.yml +++ b/.github/workflows/scorecard.yml @@ -51,7 +51,7 @@ jobs: # Upload the results as artifacts (optional). Commenting out will disable uploads of run results in SARIF # format to the repository Actions tab. - name: "Upload artifact" - uses: actions/upload-artifact@a8a3f3ad30e3422c9c7b888a15615d19a852ae32 # v3.1.3 + uses: actions/upload-artifact@c7d193f32edcb7bfad88892161225aeda64e9392 # v4.0.0 with: name: SARIF file path: results.sarif From 5d88f52f7c0bad12180de7bd4bd5a56fa7ce0ec3 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=E7=BD=97=E6=B3=BD=E8=BD=A9?= Date: Wed, 20 Dec 2023 05:18:47 +0800 Subject: [PATCH 27/27] funcr: Add LogInfoLevel Option to skip logging level in the info log (#240) * funcr: Add LogInfoLevel Option to skip logging level in the info log Benchmark before: ``` goos: darwin goarch: arm64 pkg: github.com/go-logr/logr/benchmark BenchmarkDiscardLogInfoOneArg-10 58466427 21.36 ns/op 32 B/op 1 allocs/op BenchmarkDiscardLogInfoSeveralArgs-10 24470527 49.62 ns/op 176 B/op 2 allocs/op BenchmarkDiscardLogInfoWithValues-10 21938677 47.06 ns/op 176 B/op 2 allocs/op BenchmarkDiscardLogV0Info-10 24796845 47.45 ns/op 176 B/op 2 allocs/op BenchmarkDiscardLogV9Info-10 26069977 49.02 ns/op 176 B/op 2 allocs/op BenchmarkDiscardLogError-10 23731986 47.94 ns/op 176 B/op 2 allocs/op BenchmarkDiscardWithValues-10 50995291 22.28 ns/op 64 B/op 1 allocs/op BenchmarkDiscardWithName-10 1000000000 0.4716 ns/op 0 B/op 0 allocs/op BenchmarkFuncrLogInfoOneArg-10 2684097 433.9 ns/op 1152 B/op 7 allocs/op BenchmarkFuncrJSONLogInfoOneArg-10 2413437 480.4 ns/op 1168 B/op 8 allocs/op BenchmarkFuncrLogInfoSeveralArgs-10 1261210 953.2 ns/op 1448 B/op 17 allocs/op BenchmarkFuncrJSONLogInfoSeveralArgs-10 1000000 1003 ns/op 1448 B/op 18 allocs/op BenchmarkFuncrLogInfoWithValues-10 1247379 1027 ns/op 1480 B/op 17 allocs/op BenchmarkFuncrJSONLogInfoWithValues-10 1000000 1109 ns/op 1496 B/op 18 allocs/op BenchmarkFuncrLogV0Info-10 1000000 1043 ns/op 1448 B/op 17 allocs/op BenchmarkFuncrJSONLogV0Info-10 1000000 1100 ns/op 1448 B/op 18 allocs/op BenchmarkFuncrLogV9Info-10 24429925 48.76 ns/op 176 B/op 2 allocs/op BenchmarkFuncrJSONLogV9Info-10 24799878 53.82 ns/op 176 B/op 2 allocs/op BenchmarkFuncrLogError-10 1000000 1010 ns/op 1480 B/op 19 allocs/op BenchmarkFuncrJSONLogError-10 1000000 1124 ns/op 1496 B/op 20 allocs/op BenchmarkFuncrWithValues-10 4088592 296.0 ns/op 264 B/op 8 allocs/op BenchmarkFuncrWithName-10 34046577 32.95 ns/op 96 B/op 1 allocs/op BenchmarkFuncrWithCallDepth-10 34601535 32.77 ns/op 96 B/op 1 allocs/op BenchmarkFuncrJSONLogInfoStringerValue-10 2062101 562.0 ns/op 1200 B/op 10 allocs/op BenchmarkFuncrJSONLogInfoErrorValue-10 2278339 529.9 ns/op 1200 B/op 10 allocs/op BenchmarkFuncrJSONLogInfoMarshalerValue-10 2108040 533.6 ns/op 1200 B/op 10 allocs/op ``` Benchmark after: ``` goos: darwin goarch: arm64 pkg: github.com/go-logr/logr/benchmark BenchmarkDiscardLogInfoOneArg-10 59617632 20.01 ns/op 32 B/op 1 allocs/op BenchmarkDiscardLogInfoSeveralArgs-10 26171325 47.09 ns/op 176 B/op 2 allocs/op BenchmarkDiscardLogInfoWithValues-10 25975759 45.76 ns/op 176 B/op 2 allocs/op BenchmarkDiscardLogV0Info-10 25654935 46.02 ns/op 176 B/op 2 allocs/op BenchmarkDiscardLogV9Info-10 25722668 46.00 ns/op 176 B/op 2 allocs/op BenchmarkDiscardLogError-10 25181846 45.97 ns/op 176 B/op 2 allocs/op BenchmarkDiscardWithValues-10 53340940 21.92 ns/op 64 B/op 1 allocs/op BenchmarkDiscardWithName-10 1000000000 0.4757 ns/op 0 B/op 0 allocs/op BenchmarkFuncrLogInfoOneArg-10 2887884 416.5 ns/op 1152 B/op 7 allocs/op BenchmarkFuncrJSONLogInfoOneArg-10 2556847 474.0 ns/op 1168 B/op 8 allocs/op BenchmarkFuncrLogInfoSeveralArgs-10 1280838 957.4 ns/op 1448 B/op 17 allocs/op BenchmarkFuncrJSONLogInfoSeveralArgs-10 1000000 1003 ns/op 1448 B/op 18 allocs/op BenchmarkFuncrLogInfoWithValues-10 1241484 967.6 ns/op 1480 B/op 17 allocs/op BenchmarkFuncrJSONLogInfoWithValues-10 1000000 1021 ns/op 1496 B/op 18 allocs/op BenchmarkFuncrLogV0Info-10 1202900 925.3 ns/op 1448 B/op 17 allocs/op BenchmarkFuncrJSONLogV0Info-10 1000000 1021 ns/op 1448 B/op 18 allocs/op BenchmarkFuncrLogV9Info-10 24424683 48.45 ns/op 176 B/op 2 allocs/op BenchmarkFuncrJSONLogV9Info-10 24633237 48.23 ns/op 176 B/op 2 allocs/op BenchmarkFuncrLogError-10 1000000 1066 ns/op 1480 B/op 19 allocs/op BenchmarkFuncrJSONLogError-10 1072557 1093 ns/op 1496 B/op 20 allocs/op BenchmarkFuncrWithValues-10 4094355 292.9 ns/op 264 B/op 8 allocs/op BenchmarkFuncrWithName-10 36661557 33.96 ns/op 96 B/op 1 allocs/op BenchmarkFuncrWithCallDepth-10 32008606 32.65 ns/op 96 B/op 1 allocs/op BenchmarkFuncrJSONLogInfoStringerValue-10 2329975 517.9 ns/op 1200 B/op 10 allocs/op BenchmarkFuncrJSONLogInfoErrorValue-10 2200308 522.0 ns/op 1200 B/op 10 allocs/op BenchmarkFuncrJSONLogInfoMarshalerValue-10 2242267 536.0 ns/op 1200 B/op 10 allocs/op ``` The performance is similar. Only a nil pointer check is added in the main path. Signed-off-by: spacewander * apply @thockin's suggestion Signed-off-by: spacewander --------- Signed-off-by: spacewander --- funcr/funcr.go | 14 +++++++++++++- funcr/funcr_test.go | 37 +++++++++++++++++++++++++++++++++++++ 2 files changed, 50 insertions(+), 1 deletion(-) diff --git a/funcr/funcr.go b/funcr/funcr.go index 668d37a..fb2f866 100644 --- a/funcr/funcr.go +++ b/funcr/funcr.go @@ -100,6 +100,11 @@ type Options struct { // details, see docs for Go's time.Layout. TimestampFormat string + // LogInfoLevel tells funcr what key to use to log the info level. + // If not specified, the info level will be logged as "level". + // If this is set to "", the info level will not be logged at all. + LogInfoLevel *string + // Verbosity tells funcr which V logs to produce. Higher values enable // more logs. Info logs at or below this level will be written, while logs // above this level will be discarded. @@ -213,6 +218,10 @@ func newFormatter(opts Options, outfmt outputFormat) Formatter { if opts.MaxLogDepth == 0 { opts.MaxLogDepth = defaultMaxLogDepth } + if opts.LogInfoLevel == nil { + opts.LogInfoLevel = new(string) + *opts.LogInfoLevel = "level" + } f := Formatter{ outputFormat: outfmt, prefix: "", @@ -835,7 +844,10 @@ func (f Formatter) FormatInfo(level int, msg string, kvList []any) (prefix, args if policy := f.opts.LogCaller; policy == All || policy == Info { args = append(args, "caller", f.caller()) } - args = append(args, "level", level, "msg", msg) + if key := *f.opts.LogInfoLevel; key != "" { + args = append(args, key, level) + } + args = append(args, "msg", msg) return prefix, f.render(args, kvList) } diff --git a/funcr/funcr_test.go b/funcr/funcr_test.go index 6a5c39c..6348458 100644 --- a/funcr/funcr_test.go +++ b/funcr/funcr_test.go @@ -1361,3 +1361,40 @@ func TestOptionsTimestampFormat(t *testing.T) { t.Errorf("\nexpected %q\n got %q", expect, capt.log) } } + +func TestOptionsLogInfoLevel(t *testing.T) { + testCases := []struct { + name string + level *string + expect string + }{ + { + name: "custom key", + level: ptrstr("info_level"), + expect: `"info_level"=0 "msg"="msg"`, + }, + { + name: "no level", + level: ptrstr(""), + expect: `"msg"="msg"`, + }, + { + name: "default", + level: nil, + expect: `"level"=0 "msg"="msg"`, + }, + } + + for _, tc := range testCases { + t.Run("Run: "+tc.name, func(t *testing.T) { + capt := &capture{} + sink := newSink(capt.Func, NewFormatter(Options{LogInfoLevel: tc.level})) + dSink, _ := sink.(logr.CallDepthLogSink) + sink = dSink.WithCallDepth(1) + sink.Info(0, "msg") + if capt.log != tc.expect { + t.Errorf("\nexpected %q\n got %q", tc.expect, capt.log) + } + }) + } +}