diff --git a/.github/dependabot.yml b/.github/dependabot.yml new file mode 100644 index 0000000..5ace460 --- /dev/null +++ b/.github/dependabot.yml @@ -0,0 +1,6 @@ +version: 2 +updates: + - package-ecosystem: "github-actions" + directory: "/" + schedule: + interval: "weekly" diff --git a/.github/workflows/apidiff.yaml b/.github/workflows/apidiff.yaml index a76a30c..e653923 100644 --- a/.github/workflows/apidiff.yaml +++ b/.github/workflows/apidiff.yaml @@ -2,26 +2,29 @@ name: Run apidiff on: [ pull_request ] +permissions: + contents: read + jobs: apidiff: runs-on: ubuntu-latest if: github.base_ref steps: - name: Install Go - uses: actions/setup-go@v2 + uses: actions/setup-go@cdcb36043654635271a94b9a6d1392de5bb323a7 # v5.0.1 with: - go-version: 1.18.x + go-version: 1.21.x - name: Add GOBIN to PATH run: echo "PATH=$(go env GOPATH)/bin:$PATH" >>$GITHUB_ENV - name: Install dependencies run: GO111MODULE=off go get golang.org/x/exp/cmd/apidiff - name: Checkout old code - uses: actions/checkout@v2 + uses: actions/checkout@a5ac7e51b41094c92402da3b24376905380afc29 # v4.1.6 with: ref: ${{ github.base_ref }} path: "old" - name: Checkout new code - uses: actions/checkout@v2 + uses: actions/checkout@a5ac7e51b41094c92402da3b24376905380afc29 # v4.1.6 with: path: "new" - name: APIDiff diff --git a/.github/workflows/assign.yaml b/.github/workflows/assign.yaml index e1bfb97..fdab014 100644 --- a/.github/workflows/assign.yaml +++ b/.github/workflows/assign.yaml @@ -6,11 +6,17 @@ on: pull_request_target: types: [opened, reopened] +permissions: + contents: read + jobs: assign: runs-on: ubuntu-latest + permissions: + issues: write + pull-requests: write steps: - - uses: actions/github-script@v6 + - uses: actions/github-script@60a0d83039c74a4aee543508d2ffcb1c3799cdea # v7.0.1 with: script: | github.rest.issues.addAssignees({ diff --git a/.github/workflows/lint.yaml b/.github/workflows/lint.yaml index c46cb8b..d69b256 100644 --- a/.github/workflows/lint.yaml +++ b/.github/workflows/lint.yaml @@ -2,14 +2,22 @@ name: Run lint on: [ push, pull_request ] +permissions: + contents: read + jobs: lint: runs-on: ubuntu-latest steps: - name: Checkout code - uses: actions/checkout@v2 + uses: actions/checkout@a5ac7e51b41094c92402da3b24376905380afc29 # v4.1.6 + - name: Update Go + uses: actions/setup-go@v5.0.1 + with: + go-version: '>=1.21.0' + cache: false - name: Lint - uses: golangci/golangci-lint-action@v2 + uses: golangci/golangci-lint-action@a4f60bb28d35aeee14e6880718e0c85ff1882e64 # v6.0.1 with: # version of golangci-lint to use in form of v1.2 or v1.2.3 or `latest` to use the latest version version: latest diff --git a/.github/workflows/scorecard.yml b/.github/workflows/scorecard.yml new file mode 100644 index 0000000..6ae7e2a --- /dev/null +++ b/.github/workflows/scorecard.yml @@ -0,0 +1,64 @@ +# This workflow uses actions that are not certified by GitHub. They are provided +# by a third-party and are governed by separate terms of service, privacy +# policy, and support documentation. + +name: Scorecard supply-chain security +on: + # For Branch-Protection check. Only the default branch is supported. See + # https://github.com/ossf/scorecard/blob/main/docs/checks.md#branch-protection + branch_protection_rule: + # To guarantee Maintained check is occasionally updated. See + # https://github.com/ossf/scorecard/blob/main/docs/checks.md#maintained + schedule: + - cron: '28 21 * * 1' + push: + branches: [ "master" ] + +# Declare default permissions as read only. +permissions: read-all + +jobs: + analysis: + name: Scorecard analysis + runs-on: ubuntu-latest + permissions: + # Needed to upload the results to code-scanning dashboard. + security-events: write + # Needed to publish results and get a badge (see publish_results below). + id-token: write + + steps: + - name: "Checkout code" + uses: actions/checkout@a5ac7e51b41094c92402da3b24376905380afc29 # v4.1.6 + with: + persist-credentials: false + + - name: "Run analysis" + uses: ossf/scorecard-action@dc50aa9510b46c811795eb24b2f1ba02a914e534 # v2.3.3 + with: + results_file: results.sarif + results_format: sarif + # (Optional) "write" PAT token. Uncomment the `repo_token` line below if: + # you want to enable the Branch-Protection check on a *public* repository, or + # To create the PAT, follow the steps in https://github.com/ossf/scorecard-action#authentication-with-pat. + # repo_token: ${{ secrets.SCORECARD_TOKEN }} + + # - Publish results to OpenSSF REST API for easy access by consumers + # - Allows the repository to include the Scorecard badge. + # - See https://github.com/ossf/scorecard-action#publishing-results. + publish_results: true + + # 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@65462800fd760344b1a7b4382951275a0abb4808 # v4.3.3 + with: + name: SARIF file + path: results.sarif + retention-days: 5 + + # Upload the results to GitHub's code scanning dashboard. + - name: "Upload to code-scanning" + uses: github/codeql-action/upload-sarif@b7cec7526559c32f1616476ff32d17ba4c59b2d6 # v3.25.5 + with: + sarif_file: results.sarif diff --git a/.github/workflows/tests.yaml b/.github/workflows/tests.yaml index 2b7f2b5..2c70bd4 100644 --- a/.github/workflows/tests.yaml +++ b/.github/workflows/tests.yaml @@ -2,20 +2,23 @@ name: Run tests on: [ push, pull_request ] +permissions: + contents: read + jobs: test: strategy: matrix: - version: [ '1.15', '1.16', '1.17', '1.18' ] + version: [ '1.18', '1.19', '1.20', '1.21.0-rc.4' ] platform: [ ubuntu-latest, macos-latest, windows-latest ] runs-on: ${{ matrix.platform }} steps: - name: Install Go - uses: actions/setup-go@v2 + uses: actions/setup-go@cdcb36043654635271a94b9a6d1392de5bb323a7 # v5.0.1 with: go-version: ${{ matrix.version }} - name: Checkout code - uses: actions/checkout@v2 + uses: actions/checkout@a5ac7e51b41094c92402da3b24376905380afc29 # v4.1.6 - name: Build run: go build -v ./... - name: Test diff --git a/README.md b/README.md index ab59311..7c7f0c6 100644 --- a/README.md +++ b/README.md @@ -1,6 +1,8 @@ # A minimal logging API for Go [![Go Reference](https://pkg.go.dev/badge/github.com/go-logr/logr.svg)](https://pkg.go.dev/github.com/go-logr/logr) +[![Go Report Card](https://goreportcard.com/badge/github.com/go-logr/logr)](https://goreportcard.com/report/github.com/go-logr/logr) +[![OpenSSF Scorecard](https://api.securityscorecards.dev/projects/github.com/go-logr/logr/badge)](https://securityscorecards.dev/viewer/?platform=github.com&org=go-logr&repo=logr) logr offers an(other) opinion on how Go programs and libraries can do logging without becoming coupled to a particular logging implementation. This is not @@ -73,6 +75,30 @@ received: If the Go standard library had defined an interface for logging, this project probably would not be needed. Alas, here we are. +When the Go developers started developing such an interface with +[slog](https://github.com/golang/go/issues/56345), they adopted some of the +logr design but also left out some parts and changed others: + +| Feature | logr | slog | +|---------|------|------| +| High-level API | `Logger` (passed by value) | `Logger` (passed by [pointer](https://github.com/golang/go/issues/59126)) | +| Low-level API | `LogSink` | `Handler` | +| Stack unwinding | done by `LogSink` | done by `Logger` | +| Skipping helper functions | `WithCallDepth`, `WithCallStackHelper` | [not supported by Logger](https://github.com/golang/go/issues/59145) | +| Generating a value for logging on demand | `Marshaler` | `LogValuer` | +| Log levels | >= 0, higher meaning "less important" | positive and negative, with 0 for "info" and higher meaning "more important" | +| Error log entries | always logged, don't have a verbosity level | normal log entries with level >= `LevelError` | +| Passing logger via context | `NewContext`, `FromContext` | no API | +| 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 +alternative API, with [interoperability](#slog-interoperability) provided by +some conversion functions. + ### Inspiration Before you consider this package, please read [this blog post by the @@ -118,6 +144,103 @@ There are implementations for the following logging libraries: - **github.com/go-kit/log**: [gokitlogr](https://github.com/tonglil/gokitlogr) (also compatible with github.com/go-kit/kit/log since v0.12.0) - **bytes.Buffer** (writing to a buffer): [bufrlogr](https://github.com/tonglil/buflogr) (useful for ensuring values were logged, like during testing) +## 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`. `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. + +### 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 `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. `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 +`ToSlogHandler` has to use a wrapper which adjusts the verbosity for future +log calls. + +Such an implementation should also support values that implement specific +interfaces from both packages for logging (`logr.Marshaler`, `slog.LogValuer`, +`slog.GroupValue`). logr does not convert those. + +Not supporting slog has several drawbacks: +- Recording source code locations works correctly if the handler gets called + through `slog.Logger`, but may be wrong in other cases. That's because a + `logr.Sink` does its own stack unwinding instead of using the program counter + provided by the high-level API. +- slog levels <= 0 can be mapped to logr levels by negating the level without a + loss of information. But all slog levels > 0 (e.g. `slog.LevelWarning` as + used by `slog.Logger.Warn`) must be mapped to 0 before calling the sink + because logr does not support "more important than info" levels. +- The slog group concept is supported by prefixing each key in a key/value + pair with the group names, separated by a dot. For structured output like + JSON it would be better to group the key/value pairs inside an object. +- Special slog values and interfaces don't work as expected. +- The overhead is likely to be higher. + +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 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 `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. +- `Logger.Error` is turned into a log record with `slog.LevelError` as level + and an additional attribute with `err` as key, if an error was provided. + +The main drawback is that `logr.Marshaler` will not be supported. Types should +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 + +Storing a logger in a `context.Context` is not supported by +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 ### Conceptual @@ -241,7 +364,9 @@ Otherwise, you can start out with `0` as "you always want to see this", Then gradually choose levels in between as you need them, working your way down from 10 (for debug and trace style logs) and up from 1 (for chattier -info-type logs.) +info-type logs). For reference, slog pre-defines -4 for debug logs +(corresponds to 4 in logr), which matches what is +[recommended for Kubernetes](https://github.com/kubernetes/community/blob/master/contributors/devel/sig-instrumentation/logging.md#what-method-to-use). #### How do I choose my keys? diff --git a/SECURITY.md b/SECURITY.md new file mode 100644 index 0000000..1ca756f --- /dev/null +++ b/SECURITY.md @@ -0,0 +1,18 @@ +# Security Policy + +If you have discovered a security vulnerability in this project, please report it +privately. **Do not disclose it as a public issue.** This gives us time to work with you +to fix the issue before public exposure, reducing the chance that the exploit will be +used before a patch is released. + +You may submit the report in the following ways: + +- send an email to go-logr-security@googlegroups.com +- send us a [private vulnerability report](https://github.com/go-logr/logr/security/advisories/new) + +Please provide the following information in your report: + +- A description of the vulnerability and its impact +- How to reproduce the issue + +We ask that you give us 90 days to work on a fix before public exposure. 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 cd111bc..35c7dd0 100644 --- a/benchmark/benchmark_test.go +++ b/benchmark/benchmark_test.go @@ -130,7 +130,7 @@ func doErrorValue(b *testing.B, log logr.Logger) { type Tmarshaler struct{ s string } -func (t Tmarshaler) MarshalLog() interface{} { +func (t Tmarshaler) MarshalLog() any { return t.s } @@ -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,8 +185,12 @@ func BenchmarkDiscardWithName(b *testing.B) { doWithName(b, log) } -func noopKV(prefix, args string) {} -func noopJSON(obj string) {} +// +// funcr +// + +func noopKV(_, _ string) {} +func noopJSON(_ string) {} func BenchmarkFuncrLogInfoOneArg(b *testing.B) { var log logr.Logger = funcr.New(noopKV, funcr.Options{}) 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/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/example_marshaler_secret_test.go b/example_marshaler_secret_test.go index 1e59af3..f57ecd7 100644 --- a/example_marshaler_secret_test.go +++ b/example_marshaler_secret_test.go @@ -27,7 +27,7 @@ type ComplexObjectRef struct { Secret string } -func (ref ComplexObjectRef) MarshalLog() interface{} { +func (ref ComplexObjectRef) MarshalLog() any { return struct { Name, Namespace string }{ @@ -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 12fdaf3..6c52b34 100644 --- a/example_marshaler_test.go +++ b/example_marshaler_test.go @@ -33,7 +33,7 @@ func (ref ObjectRef) String() string { return ref.Name } -func (ref ObjectRef) MarshalLog() interface{} { +func (ref ObjectRef) MarshalLog() any { // We implement fmt.Stringer for non-structured logging, but we want the // raw struct when using structured logs. Some logr implementations call // String if it is present, so we want to convert this struct to something @@ -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/example_slogr_test.go b/example_slogr_test.go new file mode 100644 index 0000000..55bae82 --- /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(_ []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/examples/slog/main.go b/examples/slog/main.go new file mode 100644 index 0000000..599d156 --- /dev/null +++ b/examples/slog/main.go @@ -0,0 +1,102 @@ +//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 slogr. +package main + +import ( + "context" + "fmt" + "log/slog" + "os" + + "github.com/go-logr/logr" + "github.com/go-logr/logr/funcr" +) + +type e struct { + str string +} + +func (e e) Error() string { + return e.str +} + +func logrHelper(log logr.Logger, msg string) { + logrHelper2(log, msg) +} + +func logrHelper2(log logr.Logger, msg string) { + log.WithCallDepth(2).Info(msg) +} + +func slogHelper(log *slog.Logger, msg string) { + slogHelper2(log, msg) +} + +func slogHelper2(log *slog.Logger, msg string) { + // slog.Logger has no API for skipping helper functions, so this gets logged as call location. + log.Info(msg) +} + +func main() { + opts := slog.HandlerOptions{ + AddSource: true, + Level: slog.Level(-1), + } + handler := slog.NewJSONHandler(os.Stderr, &opts) + logrLogger := logr.FromSlogHandler(handler) + logrExample(logrLogger) + + logrLogger = funcr.NewJSON( + func(obj string) { fmt.Println(obj) }, + funcr.Options{ + LogCaller: funcr.All, + LogTimestamp: true, + Verbosity: 1, + }) + slogLogger := slog.New(logr.ToSlogHandler(logrLogger)) + slogExample(slogLogger) +} + +func logrExample(log logr.Logger) { + log = log.WithName("my") + log = log.WithName("logger") + log = log.WithName("name") + log = log.WithValues("saved", "value") + log.Info("1) hello", "val1", 1, "val2", map[string]int{"k": 1}) + log.V(1).Info("2) you should see this") + log.V(1).V(1).Info("you should NOT see this") + log.Error(nil, "3) uh oh", "trouble", true, "reasons", []float64{0.1, 0.11, 3.14}) + log.Error(e{"an error occurred"}, "4) goodbye", "code", -1) + logrHelper(log, "5) thru a helper") +} + +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 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}) + log.Log(context.TODO(), slog.Level(-1), "2) you should see this") + log.Log(context.TODO(), slog.Level(-2), "you should NOT see this") + log.Error("3) uh oh", "trouble", true, "reasons", []float64{0.1, 0.11, 3.14}) + log.Error("4) goodbye", "code", -1, "err", e{"an error occurred"}) + slogHelper(log, "5) thru a helper") +} diff --git a/examples/tab_logger.go b/examples/tab_logger.go index 1849797..4e00598 100644 --- a/examples/tab_logger.go +++ b/examples/tab_logger.go @@ -28,7 +28,7 @@ import ( // It's terribly inefficient, and is only a basic example. type tabLogSink struct { name string - keyValues map[string]interface{} + keyValues map[string]any writer *tabwriter.Writer } @@ -36,14 +36,14 @@ var _ logr.LogSink = &tabLogSink{} // Note that Init usually takes a pointer so it can modify the receiver to save // runtime info. -func (_ *tabLogSink) Init(info logr.RuntimeInfo) { +func (*tabLogSink) Init(info logr.RuntimeInfo) { } -func (_ tabLogSink) Enabled(level int) bool { +func (tabLogSink) Enabled(level int) bool { return true } -func (l tabLogSink) Info(level int, msg string, kvs ...interface{}) { +func (l tabLogSink) Info(level int, msg string, kvs ...any) { fmt.Fprintf(l.writer, "%s\t%s\t", l.name, msg) for k, v := range l.keyValues { fmt.Fprintf(l.writer, "%s: %+v ", k, v) @@ -55,7 +55,7 @@ func (l tabLogSink) Info(level int, msg string, kvs ...interface{}) { l.writer.Flush() } -func (l tabLogSink) Error(err error, msg string, kvs ...interface{}) { +func (l tabLogSink) Error(err error, msg string, kvs ...any) { kvs = append(kvs, "error", err) l.Info(0, msg, kvs...) } @@ -68,8 +68,8 @@ func (l tabLogSink) WithName(name string) logr.LogSink { } } -func (l tabLogSink) WithValues(kvs ...interface{}) logr.LogSink { - newMap := make(map[string]interface{}, len(l.keyValues)+len(kvs)/2) +func (l tabLogSink) WithValues(kvs ...any) logr.LogSink { + newMap := make(map[string]any, len(l.keyValues)+len(kvs)/2) for k, v := range l.keyValues { newMap[k] = v } diff --git a/examples/usage_example.go b/examples/usage_example.go index a826d9c..e60db7a 100644 --- a/examples/usage_example.go +++ b/examples/usage_example.go @@ -34,34 +34,37 @@ import ( // (but a bit trickier) to use file-level "base" loggers. var objectMap = map[string]Object{ - "obj1": Object{ + "obj1": { Name: "obj1", Kind: "one", Details: 33, }, - "obj2": Object{ + "obj2": { Name: "obj2", Kind: "two", Details: "hi", }, - "obj3": Object{ + "obj3": { Name: "obj3", Kind: "one", Details: 1, }, } +// Object is an app contruct that might want to be logged. type Object struct { Name string Kind string - Details interface{} + Details any } +// Client is a simulated client in this example app. type Client struct { objects map[string]Object log logr.Logger } +// Get retrieves an object. func (c *Client) Get(key string) (Object, error) { c.log.V(1).Info("fetching object", "key", key) obj, ok := c.objects[key] @@ -72,6 +75,7 @@ func (c *Client) Get(key string) (Object, error) { return obj, nil } +// Save stores an object. func (c *Client) Save(obj Object) error { c.log.V(1).Info("saving object", "key", obj.Name, "object", obj) if rand.Intn(2) == 0 { @@ -81,6 +85,7 @@ func (c *Client) Save(obj Object) error { return nil } +// WatchNext waits for object updates. func (c *Client) WatchNext() string { time.Sleep(2 * time.Second) @@ -98,12 +103,14 @@ func (c *Client) WatchNext() string { return "" } +// Controller is the main point of this example. type Controller struct { log logr.Logger expectedKind string client *Client } +// Run starts the example controller. func (c *Controller) Run() { c.log.Info("starting reconciliation") @@ -141,6 +148,7 @@ func (c *Controller) Run() { c.log.Info("stopping reconciliation") } +// NewController allocates and initializes a Controller. func NewController(log logr.Logger, objectKind string) *Controller { ctrlLogger := log.WithName("controller").WithName(objectKind) client := &Client{ 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/example_formatter_test.go b/funcr/example_formatter_test.go index e5ed6ec..474e510 100644 --- a/funcr/example_formatter_test.go +++ b/funcr/example_formatter_test.go @@ -45,7 +45,7 @@ func (l stdoutlogger) WithName(name string) logr.LogSink { return &l } -func (l stdoutlogger) WithValues(kvList ...interface{}) logr.LogSink { +func (l stdoutlogger) WithValues(kvList ...any) logr.LogSink { l.Formatter.AddValues(kvList) return &l } @@ -55,12 +55,12 @@ func (l stdoutlogger) WithCallDepth(depth int) logr.LogSink { return &l } -func (l stdoutlogger) Info(level int, msg string, kvList ...interface{}) { +func (l stdoutlogger) Info(level int, msg string, kvList ...any) { prefix, args := l.FormatInfo(level, msg, kvList) l.write("INFO", prefix, args) } -func (l stdoutlogger) Error(err error, msg string, kvList ...interface{}) { +func (l stdoutlogger) Error(err error, msg string, kvList ...any) { prefix, args := l.FormatError(err, msg, kvList) l.write("ERROR", prefix, args) } diff --git a/funcr/example_test.go b/funcr/example_test.go index 53373a2..4918154 100644 --- a/funcr/example_test.go +++ b/funcr/example_test.go @@ -74,7 +74,7 @@ func ExampleOptions() { func ExampleOptions_renderHooks() { // prefix all builtin keys with "log:" - prefixSpecialKeys := func(kvList []interface{}) []interface{} { + prefixSpecialKeys := func(kvList []any) []any { for i := 0; i < len(kvList); i += 2 { k, _ := kvList[i].(string) kvList[i] = "log:" + k @@ -83,8 +83,8 @@ func ExampleOptions_renderHooks() { } // present saved values as a single JSON object - valuesAsObject := func(kvList []interface{}) []interface{} { - return []interface{}{"labels", funcr.PseudoStruct(kvList)} + valuesAsObject := func(kvList []any) []any { + return []any{"labels", funcr.PseudoStruct(kvList)} } var log logr.Logger = funcr.NewJSON( @@ -104,7 +104,7 @@ func ExamplePseudoStruct() { var log logr.Logger = funcr.NewJSON( func(obj string) { fmt.Println(obj) }, funcr.Options{}) - kv := []interface{}{ + kv := []any{ "field1", 12345, "field2", true, } diff --git a/funcr/funcr.go b/funcr/funcr.go index e52f0cd..30568e7 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. @@ -116,17 +121,17 @@ type Options struct { // Equivalent hooks are offered for key-value pairs saved via // logr.Logger.WithValues or Formatter.AddValues (see RenderValuesHook) and // for user-provided pairs (see RenderArgsHook). - RenderBuiltinsHook func(kvList []interface{}) []interface{} + RenderBuiltinsHook func(kvList []any) []any // RenderValuesHook is the same as RenderBuiltinsHook, except that it is // only called for key-value pairs saved via logr.Logger.WithValues. See // RenderBuiltinsHook for more details. - RenderValuesHook func(kvList []interface{}) []interface{} + RenderValuesHook func(kvList []any) []any // RenderArgsHook is the same as RenderBuiltinsHook, except that it is only // called for key-value pairs passed directly to Info and Error. See // RenderBuiltinsHook for more details. - RenderArgsHook func(kvList []interface{}) []interface{} + RenderArgsHook func(kvList []any) []any // MaxLogDepth tells funcr how many levels of nested fields (e.g. a struct // that contains a struct, etc.) it may log. Every time it finds a struct, @@ -163,7 +168,7 @@ func (l fnlogger) WithName(name string) logr.LogSink { return &l } -func (l fnlogger) WithValues(kvList ...interface{}) logr.LogSink { +func (l fnlogger) WithValues(kvList ...any) logr.LogSink { l.Formatter.AddValues(kvList) return &l } @@ -173,12 +178,12 @@ func (l fnlogger) WithCallDepth(depth int) logr.LogSink { return &l } -func (l fnlogger) Info(level int, msg string, kvList ...interface{}) { +func (l fnlogger) Info(level int, msg string, kvList ...any) { prefix, args := l.FormatInfo(level, msg, kvList) l.write(prefix, args) } -func (l fnlogger) Error(err error, msg string, kvList ...interface{}) { +func (l fnlogger) Error(err error, msg string, kvList ...any) { prefix, args := l.FormatError(err, msg, kvList) l.write(prefix, args) } @@ -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: "", @@ -229,10 +238,12 @@ func newFormatter(opts Options, outfmt outputFormat) Formatter { type Formatter struct { outputFormat outputFormat prefix string - values []interface{} + values []any valuesStr string depth int opts *Options + groupName string // for slog groups + groups []groupDef } // outputFormat indicates which outputFormat to use. @@ -245,70 +256,139 @@ const ( outputJSON ) +// groupDef represents a saved group. The values may be empty, but we don't +// know if we need to render the group until the final record is rendered. +type groupDef struct { + name string + values string +} + // PseudoStruct is a list of key-value pairs that gets logged as a struct. -type PseudoStruct []interface{} +type PseudoStruct []any // render produces a log line, ready to use. -func (f Formatter) render(builtins, args []interface{}) string { +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 record } + + // Render builtins 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 + f.flatten(buf, vals, false) // keys are ours, no need to escape continuing := len(builtins) > 0 - if len(f.valuesStr) > 0 { + + // Turn the inner-most group into a string + argsStr := func() string { + buf := bytes.NewBuffer(make([]byte, 0, 1024)) + + vals = args + if hook := f.opts.RenderArgsHook; hook != nil { + vals = hook(f.sanitize(vals)) + } + f.flatten(buf, vals, true) // escape user-provided keys + + return buf.String() + }() + + // Render the stack of groups from the inside out. + bodyStr := f.renderGroup(f.groupName, f.valuesStr, argsStr) + for i := len(f.groups) - 1; i >= 0; i-- { + grp := &f.groups[i] + if grp.values == "" && bodyStr == "" { + // no contents, so we must elide the whole group + continue + } + bodyStr = f.renderGroup(grp.name, grp.values, bodyStr) + } + + if bodyStr != "" { if continuing { - if f.outputFormat == outputJSON { - buf.WriteByte(',') - } else { - buf.WriteByte(' ') - } + buf.WriteByte(f.comma()) } + buf.WriteString(bodyStr) + } + + if f.outputFormat == outputJSON { + buf.WriteByte('}') // for the whole record + } + + return buf.String() +} + +// renderGroup returns a string representation of the named group with rendered +// values and args. If the name is empty, this will return the values and args, +// joined. If the name is not empty, this will return a single key-value pair, +// where the value is a grouping of the values and args. If the values and +// args are both empty, this will return an empty string, even if the name was +// specified. +func (f Formatter) renderGroup(name string, values string, args string) string { + buf := bytes.NewBuffer(make([]byte, 0, 1024)) + + needClosingBrace := false + if name != "" && (values != "" || args != "") { + buf.WriteString(f.quoted(name, true)) // escape user-provided keys + buf.WriteByte(f.colon()) + buf.WriteByte('{') + needClosingBrace = true + } + + continuing := false + if values != "" { + buf.WriteString(values) continuing = true - buf.WriteString(f.valuesStr) } - vals = args - if hook := f.opts.RenderArgsHook; hook != nil { - vals = hook(f.sanitize(vals)) + + if args != "" { + if continuing { + buf.WriteByte(f.comma()) + } + buf.WriteString(args) } - f.flatten(buf, vals, continuing, true) // escape user-provided keys - if f.outputFormat == outputJSON { + + if needClosingBrace { buf.WriteByte('}') } + return buf.String() } -// flatten renders a list of key-value pairs into a buffer. If continuing is -// true, it assumes that the buffer has previous values and will emit a -// separator (which depends on the output format) before the first pair it -// writes. If escapeKeys is true, the keys are assumed to have -// non-JSON-compatible characters in them and must be evaluated for escapes. +// flatten renders a list of key-value pairs into a buffer. If escapeKeys is +// true, the keys are assumed to have non-JSON-compatible characters in them +// and must be evaluated for escapes. // // This function returns a potentially modified version of kvList, which // ensures that there is a value for every key (adding a value if needed) and // that each key is a string (substituting a key if needed). -func (f Formatter) flatten(buf *bytes.Buffer, kvList []interface{}, continuing bool, escapeKeys bool) []interface{} { +func (f Formatter) flatten(buf *bytes.Buffer, kvList []any, escapeKeys bool) []any { // This logic overlaps with sanitize() but saves one type-cast per key, // which can be measurable. 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 } v := kvList[i+1] - if i > 0 || continuing { + if i > 0 { 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. @@ -316,25 +396,36 @@ func (f Formatter) flatten(buf *bytes.Buffer, kvList []interface{}, continuing b } } - if escapeKeys { - buf.WriteString(prettyString(k)) - } else { - // this is faster - buf.WriteByte('"') - buf.WriteString(k) - buf.WriteByte('"') - } - if f.outputFormat == outputJSON { - buf.WriteByte(':') - } else { - buf.WriteByte('=') - } + buf.WriteString(f.quoted(k, escapeKeys)) + buf.WriteByte(f.colon()) buf.WriteString(f.pretty(v)) } return kvList } -func (f Formatter) pretty(value interface{}) string { +func (f Formatter) quoted(str string, escape bool) string { + if escape { + return prettyString(str) + } + // this is faster + return `"` + str + `"` +} + +func (f Formatter) comma() byte { + if f.outputFormat == outputJSON { + return ',' + } + 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) } @@ -343,7 +434,7 @@ const ( ) // TODO: This is not fast. Most of the overhead goes here. -func (f Formatter) prettyWithFlags(value interface{}, flags uint32, depth int) string { +func (f Formatter) prettyWithFlags(value any, flags uint32, depth int) string { if depth > f.opts.MaxLogDepth { return `""` } @@ -407,12 +498,12 @@ func (f Formatter) prettyWithFlags(value interface{}, flags uint32, depth int) s } 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 buf.WriteString(prettyString(k)) - buf.WriteByte(':') + buf.WriteByte(f.colon()) buf.WriteString(f.prettyWithFlags(v[i+1], 0, depth+1)) } if flags&flagRawStruct == 0 { @@ -481,7 +572,7 @@ func (f Formatter) prettyWithFlags(value interface{}, flags uint32, depth int) s 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 == "" { @@ -492,10 +583,8 @@ func (f Formatter) prettyWithFlags(value interface{}, flags uint32, depth int) s name = fld.Name } // field names can't contain characters which need escaping - buf.WriteByte('"') - buf.WriteString(name) - buf.WriteByte('"') - buf.WriteByte(':') + buf.WriteString(f.quoted(name, false)) + buf.WriteByte(f.colon()) buf.WriteString(f.prettyWithFlags(v.Field(i).Interface(), 0, depth+1)) } if flags&flagRawStruct == 0 { @@ -520,7 +609,7 @@ func (f Formatter) prettyWithFlags(value interface{}, flags uint32, depth int) s 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)) @@ -534,7 +623,7 @@ func (f Formatter) prettyWithFlags(value interface{}, flags uint32, depth int) s i := 0 for it.Next() { if i > 0 { - buf.WriteByte(',') + buf.WriteByte(f.comma()) } // If a map key supports TextMarshaler, use it. keystr := "" @@ -556,7 +645,7 @@ func (f Formatter) prettyWithFlags(value interface{}, flags uint32, depth int) s } } buf.WriteString(keystr) - buf.WriteByte(':') + buf.WriteByte(f.colon()) buf.WriteString(f.prettyWithFlags(it.Value().Interface(), 0, depth+1)) i++ } @@ -614,7 +703,7 @@ func isEmpty(v reflect.Value) bool { return false } -func invokeMarshaler(m logr.Marshaler) (ret interface{}) { +func invokeMarshaler(m logr.Marshaler) (ret any) { defer func() { if r := recover(); r != nil { ret = fmt.Sprintf("", r) @@ -675,12 +764,12 @@ func (f Formatter) caller() Caller { const noValue = "" -func (f Formatter) nonStringKey(v interface{}) string { +func (f Formatter) nonStringKey(v any) string { return fmt.Sprintf("", f.snippet(v)) } // snippet produces a short snippet string of an arbitrary value. -func (f Formatter) snippet(v interface{}) string { +func (f Formatter) snippet(v any) string { const snipLen = 16 snip := f.pretty(v) @@ -693,7 +782,7 @@ func (f Formatter) snippet(v interface{}) string { // sanitize ensures that a list of key-value pairs has a value for every key // (adding a value if needed) and that each key is a string (substituting a key // if needed). -func (f Formatter) sanitize(kvList []interface{}) []interface{} { +func (f Formatter) sanitize(kvList []any) []any { if len(kvList)%2 != 0 { kvList = append(kvList, noValue) } @@ -706,6 +795,24 @@ func (f Formatter) sanitize(kvList []interface{}) []interface{} { 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(name string) { + // Unnamed groups are just inlined. + if name == "" { + return + } + + n := len(f.groups) + f.groups = append(f.groups[:n:n], groupDef{f.groupName, f.valuesStr}) + + // Start collecting new values. + f.groupName = name + 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. @@ -727,8 +834,8 @@ func (f Formatter) GetDepth() int { // FormatInfo renders an Info log message into strings. The prefix will be // empty when no names were set (via AddNames), or when the output is // configured for JSON. -func (f Formatter) FormatInfo(level int, msg string, kvList []interface{}) (prefix, argsStr string) { - args := make([]interface{}, 0, 64) // using a constant here impacts perf +func (f Formatter) FormatInfo(level int, msg string, kvList []any) (prefix, argsStr string) { + args := make([]any, 0, 64) // using a constant here impacts perf prefix = f.prefix if f.outputFormat == outputJSON { args = append(args, "logger", prefix) @@ -740,15 +847,18 @@ func (f Formatter) FormatInfo(level int, msg string, kvList []interface{}) (pref 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) } // FormatError renders an Error log message into strings. The prefix will be -// empty when no names were set (via AddNames), or when the output is +// empty when no names were set (via AddNames), or when the output is // configured for JSON. -func (f Formatter) FormatError(err error, msg string, kvList []interface{}) (prefix, argsStr string) { - args := make([]interface{}, 0, 64) // using a constant here impacts perf +func (f Formatter) FormatError(err error, msg string, kvList []any) (prefix, argsStr string) { + args := make([]any, 0, 64) // using a constant here impacts perf prefix = f.prefix if f.outputFormat == outputJSON { args = append(args, "logger", prefix) @@ -761,12 +871,12 @@ func (f Formatter) FormatError(err error, msg string, kvList []interface{}) (pre args = append(args, "caller", f.caller()) } args = append(args, "msg", msg) - var loggableErr interface{} + var loggableErr any if err != nil { loggableErr = err.Error() } args = append(args, "error", loggableErr) - return f.prefix, f.render(args, kvList) + return prefix, f.render(args, kvList) } // AddName appends the specified name. funcr uses '/' characters to separate @@ -781,7 +891,7 @@ func (f *Formatter) AddName(name string) { // AddValues adds key-value pairs to the set of saved values to be logged with // each log line. -func (f *Formatter) AddValues(kvList []interface{}) { +func (f *Formatter) AddValues(kvList []any) { // Three slice args forces a copy. n := len(f.values) f.values = append(f.values[:n:n], kvList...) @@ -793,7 +903,7 @@ func (f *Formatter) AddValues(kvList []interface{}) { // Pre-render values, so we don't have to do it on each Info/Error call. buf := bytes.NewBuffer(make([]byte, 0, 1024)) - f.flatten(buf, vals, false, true) // escape user-provided keys + f.flatten(buf, vals, true) // escape user-provided keys f.valuesStr = buf.String() } diff --git a/funcr/funcr_test.go b/funcr/funcr_test.go index 8af3970..6900a2d 100644 --- a/funcr/funcr_test.go +++ b/funcr/funcr_test.go @@ -54,7 +54,7 @@ func (p pointErr) MarshalText() ([]byte, error) { // Logging this should result in the MarshalLog() value. type Tmarshaler struct{ val string } -func (t Tmarshaler) MarshalLog() interface{} { +func (t Tmarshaler) MarshalLog() any { return struct{ Inner string }{"I am a logr.Marshaler"} } @@ -69,7 +69,7 @@ func (t Tmarshaler) Error() string { // Logging this should result in a panic. type Tmarshalerpanic struct{ val string } -func (t Tmarshalerpanic) MarshalLog() interface{} { +func (t Tmarshalerpanic) MarshalLog() any { panic("Tmarshalerpanic") } @@ -251,7 +251,7 @@ func TestPretty(t *testing.T) { } cases := []struct { - val interface{} + val any exp string // used in cases where JSON can't handle it }{{ val: "strval", @@ -402,11 +402,11 @@ func TestPretty(t *testing.T) { val: struct { A *int B *int - C interface{} - D interface{} + C any + D any }{ B: ptrint(1), - D: interface{}(2), + D: any(2), }, }, { val: Tmarshaler{"foobar"}, @@ -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 := "" @@ -678,7 +678,7 @@ func TestPretty(t *testing.T) { } } -func makeKV(args ...interface{}) []interface{} { +func makeKV(args ...any) []any { return args } @@ -694,9 +694,9 @@ func TestRender(t *testing.T) { testCases := []struct { name string - builtins []interface{} - values []interface{} - args []interface{} + builtins []any + values []any + args []any expectKV string expectJSON string }{{ @@ -705,9 +705,9 @@ func TestRender(t *testing.T) { expectJSON: "{}", }, { name: "empty", - builtins: []interface{}{}, - values: []interface{}{}, - args: []interface{}{}, + builtins: []any{}, + values: []any{}, + args: []any{}, expectKV: "", expectJSON: "{}", }, { @@ -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,22 +759,22 @@ 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", args: makeKV("key", &Trawjson{}), - expectKV: `"key"={"message":[]}`, + expectKV: `"key"={"message"=[]}`, expectJSON: `{"key":{"message":null}}`, }} @@ -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) { @@ -800,12 +800,12 @@ func TestRender(t *testing.T) { func TestSanitize(t *testing.T) { testCases := []struct { name string - kv []interface{} - expect []interface{} + kv []any + expect []any }{{ name: "empty", - kv: []interface{}{}, - expect: []interface{}{}, + kv: []any{}, + expect: []any{}, }, { name: "already sane", kv: makeKV("int", 1, "str", "ABC", "bool", true), @@ -840,7 +840,7 @@ func TestSanitize(t *testing.T) { func TestEnabled(t *testing.T) { t.Run("default V", func(t *testing.T) { - log := newSink(func(prefix, args string) {}, NewFormatter(Options{})) + log := newSink(func(_, _ string) {}, NewFormatter(Options{})) if !log.Enabled(0) { t.Errorf("expected true") } @@ -849,7 +849,7 @@ func TestEnabled(t *testing.T) { } }) t.Run("V=9", func(t *testing.T) { - log := newSink(func(prefix, args string) {}, NewFormatter(Options{Verbosity: 9})) + log := newSink(func(_, _ string) {}, NewFormatter(Options{Verbosity: 9})) if !log.Enabled(8) { t.Errorf("expected true") } @@ -867,212 +867,295 @@ type capture struct { } func (c *capture) Func(prefix, args string) { - c.log = prefix + " " + args + space := " " + if len(prefix) == 0 { + space = "" + } + c.log = prefix + space + args } func TestInfo(t *testing.T) { testCases := []struct { - name string - args []interface{} - expect string + name string + args []any + expectKV string + expectJSON string }{{ - name: "just msg", - args: makeKV(), - expect: ` "level"=0 "msg"="msg"`, + name: "just msg", + args: makeKV(), + expectKV: `"level"=0 "msg"="msg"`, + expectJSON: `{"logger":"","level":0,"msg":"msg"}`, }, { - name: "primitives", - args: makeKV("int", 1, "str", "ABC", "bool", true), - expect: ` "level"=0 "msg"="msg" "int"=1 "str"="ABC" "bool"=true`, + name: "primitives", + args: makeKV("int", 1, "str", "ABC", "bool", true), + expectKV: `"level"=0 "msg"="msg" "int"=1 "str"="ABC" "bool"=true`, + expectJSON: `{"logger":"","level":0,"msg":"msg","int":1,"str":"ABC","bool":true}`, }} for _, tc := range testCases { - t.Run(tc.name, func(t *testing.T) { - cap := &capture{} - sink := newSink(cap.Func, NewFormatter(Options{})) + t.Run("KV: "+tc.name, func(t *testing.T) { + capt := &capture{} + sink := newSink(capt.Func, NewFormatter(Options{})) + sink.Info(0, "msg", tc.args...) + if capt.log != tc.expectKV { + t.Errorf("\nexpected %q\n got %q", tc.expectKV, capt.log) + } + }) + t.Run("JSON: "+tc.name, func(t *testing.T) { + capt := &capture{} + sink := newSink(capt.Func, NewFormatterJSON(Options{})) sink.Info(0, "msg", tc.args...) - if cap.log != tc.expect { - t.Errorf("\nexpected %q\n got %q", tc.expect, cap.log) + if capt.log != tc.expectJSON { + t.Errorf("\nexpected %q\n got %q", tc.expectJSON, capt.log) } }) } } func TestInfoWithCaller(t *testing.T) { - t.Run("LogCaller=All", func(t *testing.T) { - cap := &capture{} - sink := newSink(cap.Func, NewFormatter(Options{LogCaller: All})) + t.Run("KV: LogCaller=All", func(t *testing.T) { + capt := &capture{} + 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) - if cap.log != expect { - t.Errorf("\nexpected %q\n got %q", expect, cap.log) + 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) - if cap.log != expect { - t.Errorf("\nexpected %q\n got %q", expect, cap.log) + 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) } }) - t.Run("LogCaller=All, LogCallerFunc=true", func(t *testing.T) { - thisFunc := "github.com/go-logr/logr/funcr.TestInfoWithCaller.func2" - cap := &capture{} - sink := newSink(cap.Func, NewFormatter(Options{LogCaller: All, LogCallerFunc: true})) + t.Run("JSON: LogCaller=All", func(t *testing.T) { + capt := &capture{} + sink := newSink(capt.Func, NewFormatterJSON(Options{LogCaller: All})) 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) - if cap.log != expect { - t.Errorf("\nexpected %q\n got %q", expect, cap.log) + expect := fmt.Sprintf(`{"logger":"","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,"function":%q} "msg"="msg" "error"="error"`, filepath.Base(file), line-1, thisFunc) - if cap.log != expect { - t.Errorf("\nexpected %q\n got %q", expect, cap.log) + expect = fmt.Sprintf(`{"logger":"","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) + } + }) + t.Run("KV: LogCaller=All, LogCallerFunc=true", func(t *testing.T) { + thisFunc := "github.com/go-logr/logr/funcr.TestInfoWithCaller.func3" + capt := &capture{} + 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) + 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) + if capt.log != expect { + t.Errorf("\nexpected %q\n got %q", expect, capt.log) + } + }) + t.Run("JSON: LogCaller=All, LogCallerFunc=true", func(t *testing.T) { + thisFunc := "github.com/go-logr/logr/funcr.TestInfoWithCaller.func4" + capt := &capture{} + sink := newSink(capt.Func, NewFormatterJSON(Options{LogCaller: All, LogCallerFunc: true})) + sink.Info(0, "msg") + _, file, line, _ := runtime.Caller(0) + expect := fmt.Sprintf(`{"logger":"","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(`{"logger":"","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) } }) t.Run("LogCaller=Info", func(t *testing.T) { - cap := &capture{} - sink := newSink(cap.Func, NewFormatter(Options{LogCaller: Info})) + capt := &capture{} + 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) - if cap.log != expect { - t.Errorf("\nexpected %q\n got %q", expect, cap.log) + 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") - expect = ` "msg"="msg" "error"="error"` - if cap.log != expect { - t.Errorf("\nexpected %q\n got %q", expect, cap.log) + expect = `"msg"="msg" "error"="error"` + if capt.log != expect { + t.Errorf("\nexpected %q\n got %q", expect, capt.log) } }) t.Run("LogCaller=Error", func(t *testing.T) { - cap := &capture{} - sink := newSink(cap.Func, NewFormatter(Options{LogCaller: Error})) + capt := &capture{} + sink := newSink(capt.Func, NewFormatter(Options{LogCaller: Error})) sink.Info(0, "msg") - expect := ` "level"=0 "msg"="msg"` - if cap.log != expect { - t.Errorf("\nexpected %q\n got %q", expect, cap.log) + expect := `"level"=0 "msg"="msg"` + 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) - if cap.log != expect { - t.Errorf("\nexpected %q\n got %q", expect, cap.log) + 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) } }) t.Run("LogCaller=None", func(t *testing.T) { - cap := &capture{} - sink := newSink(cap.Func, NewFormatter(Options{LogCaller: None})) + capt := &capture{} + sink := newSink(capt.Func, NewFormatter(Options{LogCaller: None})) sink.Info(0, "msg") - expect := ` "level"=0 "msg"="msg"` - if cap.log != expect { - t.Errorf("\nexpected %q\n got %q", expect, cap.log) + expect := `"level"=0 "msg"="msg"` + if capt.log != expect { + t.Errorf("\nexpected %q\n got %q", expect, capt.log) } sink.Error(fmt.Errorf("error"), "msg") - expect = ` "msg"="msg" "error"="error"` - if cap.log != expect { - t.Errorf("\nexpected %q\n got %q", expect, cap.log) + expect = `"msg"="msg" "error"="error"` + if capt.log != expect { + t.Errorf("\nexpected %q\n got %q", expect, capt.log) } }) } func TestError(t *testing.T) { testCases := []struct { - name string - args []interface{} - expect string + name string + args []any + expectKV string + expectJSON string }{{ - name: "just msg", - args: makeKV(), - expect: ` "msg"="msg" "error"="err"`, + name: "just msg", + args: makeKV(), + expectKV: `"msg"="msg" "error"="err"`, + expectJSON: `{"logger":"","msg":"msg","error":"err"}`, }, { - name: "primitives", - args: makeKV("int", 1, "str", "ABC", "bool", true), - expect: ` "msg"="msg" "error"="err" "int"=1 "str"="ABC" "bool"=true`, + name: "primitives", + args: makeKV("int", 1, "str", "ABC", "bool", true), + expectKV: `"msg"="msg" "error"="err" "int"=1 "str"="ABC" "bool"=true`, + expectJSON: `{"logger":"","msg":"msg","error":"err","int":1,"str":"ABC","bool":true}`, }} for _, tc := range testCases { - t.Run(tc.name, func(t *testing.T) { - cap := &capture{} - sink := newSink(cap.Func, NewFormatter(Options{})) + t.Run("KV: "+tc.name, func(t *testing.T) { + capt := &capture{} + sink := newSink(capt.Func, NewFormatter(Options{})) + sink.Error(fmt.Errorf("err"), "msg", tc.args...) + if capt.log != tc.expectKV { + t.Errorf("\nexpected %q\n got %q", tc.expectKV, capt.log) + } + }) + t.Run("JSON: "+tc.name, func(t *testing.T) { + capt := &capture{} + sink := newSink(capt.Func, NewFormatterJSON(Options{})) sink.Error(fmt.Errorf("err"), "msg", tc.args...) - if cap.log != tc.expect { - t.Errorf("\nexpected %q\n got %q", tc.expect, cap.log) + if capt.log != tc.expectJSON { + t.Errorf("\nexpected %q\n got %q", tc.expectJSON, capt.log) } }) } } func TestErrorWithCaller(t *testing.T) { - t.Run("LogCaller=All", func(t *testing.T) { - cap := &capture{} - sink := newSink(cap.Func, NewFormatter(Options{LogCaller: All})) + t.Run("KV: LogCaller=All", func(t *testing.T) { + capt := &capture{} + 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) + if capt.log != expect { + t.Errorf("\nexpected %q\n got %q", expect, capt.log) + } + }) + t.Run("JSON: LogCaller=All", func(t *testing.T) { + capt := &capture{} + sink := newSink(capt.Func, NewFormatterJSON(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) - if cap.log != expect { - t.Errorf("\nexpected %q\n got %q", expect, cap.log) + expect := fmt.Sprintf(`{"logger":"","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) } }) t.Run("LogCaller=Error", func(t *testing.T) { - cap := &capture{} - sink := newSink(cap.Func, NewFormatter(Options{LogCaller: Error})) + capt := &capture{} + 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) - if cap.log != expect { - t.Errorf("\nexpected %q\n got %q", expect, cap.log) + 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) } }) t.Run("LogCaller=Info", func(t *testing.T) { - cap := &capture{} - sink := newSink(cap.Func, NewFormatter(Options{LogCaller: Info})) + capt := &capture{} + sink := newSink(capt.Func, NewFormatter(Options{LogCaller: Info})) sink.Error(fmt.Errorf("err"), "msg") - expect := ` "msg"="msg" "error"="err"` - if cap.log != expect { - t.Errorf("\nexpected %q\n got %q", expect, cap.log) + expect := `"msg"="msg" "error"="err"` + if capt.log != expect { + t.Errorf("\nexpected %q\n got %q", expect, capt.log) } }) t.Run("LogCaller=None", func(t *testing.T) { - cap := &capture{} - sink := newSink(cap.Func, NewFormatter(Options{LogCaller: None})) + capt := &capture{} + sink := newSink(capt.Func, NewFormatter(Options{LogCaller: None})) sink.Error(fmt.Errorf("err"), "msg") - expect := ` "msg"="msg" "error"="err"` - if cap.log != expect { - t.Errorf("\nexpected %q\n got %q", expect, cap.log) + expect := `"msg"="msg" "error"="err"` + if capt.log != expect { + t.Errorf("\nexpected %q\n got %q", expect, capt.log) } }) } func TestInfoWithName(t *testing.T) { testCases := []struct { - name string - names []string - args []interface{} - expect string + name string + names []string + args []any + expectKV string + expectJSON string }{{ - name: "one", - names: []string{"pfx1"}, - args: makeKV("k", "v"), - expect: `pfx1 "level"=0 "msg"="msg" "k"="v"`, - }, { - name: "two", - names: []string{"pfx1", "pfx2"}, - args: makeKV("k", "v"), - expect: `pfx1/pfx2 "level"=0 "msg"="msg" "k"="v"`, + name: "one", + names: []string{"pfx1"}, + args: makeKV("k", "v"), + expectKV: `pfx1 "level"=0 "msg"="msg" "k"="v"`, + expectJSON: `{"logger":"pfx1","level":0,"msg":"msg","k":"v"}`, + }, { + name: "two", + names: []string{"pfx1", "pfx2"}, + args: makeKV("k", "v"), + expectKV: `pfx1/pfx2 "level"=0 "msg"="msg" "k"="v"`, + expectJSON: `{"logger":"pfx1/pfx2","level":0,"msg":"msg","k":"v"}`, }} for _, tc := range testCases { - t.Run(tc.name, func(t *testing.T) { - cap := &capture{} - sink := newSink(cap.Func, NewFormatter(Options{})) + t.Run("KV: "+tc.name, func(t *testing.T) { + capt := &capture{} + sink := newSink(capt.Func, NewFormatter(Options{})) + for _, n := range tc.names { + sink = sink.WithName(n) + } + sink.Info(0, "msg", tc.args...) + if capt.log != tc.expectKV { + t.Errorf("\nexpected %q\n got %q", tc.expectKV, capt.log) + } + }) + t.Run("JSON: "+tc.name, func(t *testing.T) { + capt := &capture{} + sink := newSink(capt.Func, NewFormatterJSON(Options{})) for _, n := range tc.names { sink = sink.WithName(n) } sink.Info(0, "msg", tc.args...) - if cap.log != tc.expect { - t.Errorf("\nexpected %q\n got %q", tc.expect, cap.log) + if capt.log != tc.expectJSON { + t.Errorf("\nexpected %q\n got %q", tc.expectJSON, capt.log) } }) } @@ -1080,32 +1163,46 @@ func TestInfoWithName(t *testing.T) { func TestErrorWithName(t *testing.T) { testCases := []struct { - name string - names []string - args []interface{} - expect string + name string + names []string + args []any + expectKV string + expectJSON string }{{ - name: "one", - names: []string{"pfx1"}, - args: makeKV("k", "v"), - expect: `pfx1 "msg"="msg" "error"="err" "k"="v"`, - }, { - name: "two", - names: []string{"pfx1", "pfx2"}, - args: makeKV("k", "v"), - expect: `pfx1/pfx2 "msg"="msg" "error"="err" "k"="v"`, + name: "one", + names: []string{"pfx1"}, + args: makeKV("k", "v"), + expectKV: `pfx1 "msg"="msg" "error"="err" "k"="v"`, + expectJSON: `{"logger":"pfx1","msg":"msg","error":"err","k":"v"}`, + }, { + name: "two", + names: []string{"pfx1", "pfx2"}, + args: makeKV("k", "v"), + expectKV: `pfx1/pfx2 "msg"="msg" "error"="err" "k"="v"`, + expectJSON: `{"logger":"pfx1/pfx2","msg":"msg","error":"err","k":"v"}`, }} for _, tc := range testCases { - t.Run(tc.name, func(t *testing.T) { - cap := &capture{} - sink := newSink(cap.Func, NewFormatter(Options{})) + t.Run("KV: "+tc.name, func(t *testing.T) { + capt := &capture{} + sink := newSink(capt.Func, NewFormatter(Options{})) for _, n := range tc.names { sink = sink.WithName(n) } sink.Error(fmt.Errorf("err"), "msg", tc.args...) - if cap.log != tc.expect { - t.Errorf("\nexpected %q\n got %q", tc.expect, cap.log) + if capt.log != tc.expectKV { + t.Errorf("\nexpected %q\n got %q", tc.expectKV, capt.log) + } + }) + t.Run("JSON: "+tc.name, func(t *testing.T) { + capt := &capture{} + sink := newSink(capt.Func, NewFormatterJSON(Options{})) + for _, n := range tc.names { + sink = sink.WithName(n) + } + sink.Error(fmt.Errorf("err"), "msg", tc.args...) + if capt.log != tc.expectJSON { + t.Errorf("\nexpected %q\n got %q", tc.expectJSON, capt.log) } }) } @@ -1113,40 +1210,54 @@ func TestErrorWithName(t *testing.T) { func TestInfoWithValues(t *testing.T) { testCases := []struct { - name string - values []interface{} - args []interface{} - expect string + name string + values []any + args []any + expectKV string + expectJSON string }{{ - name: "zero", - values: makeKV(), - args: makeKV("k", "v"), - expect: ` "level"=0 "msg"="msg" "k"="v"`, - }, { - name: "one", - values: makeKV("one", 1), - args: makeKV("k", "v"), - expect: ` "level"=0 "msg"="msg" "one"=1 "k"="v"`, - }, { - name: "two", - values: makeKV("one", 1, "two", 2), - args: makeKV("k", "v"), - expect: ` "level"=0 "msg"="msg" "one"=1 "two"=2 "k"="v"`, - }, { - name: "dangling", - values: makeKV("dangling"), - args: makeKV("k", "v"), - expect: ` "level"=0 "msg"="msg" "dangling"="" "k"="v"`, + name: "zero", + values: makeKV(), + args: makeKV("k", "v"), + expectKV: `"level"=0 "msg"="msg" "k"="v"`, + expectJSON: `{"logger":"","level":0,"msg":"msg","k":"v"}`, + }, { + name: "one", + values: makeKV("one", 1), + args: makeKV("k", "v"), + expectKV: `"level"=0 "msg"="msg" "one"=1 "k"="v"`, + expectJSON: `{"logger":"","level":0,"msg":"msg","one":1,"k":"v"}`, + }, { + name: "two", + values: makeKV("one", 1, "two", 2), + args: makeKV("k", "v"), + expectKV: `"level"=0 "msg"="msg" "one"=1 "two"=2 "k"="v"`, + expectJSON: `{"logger":"","level":0,"msg":"msg","one":1,"two":2,"k":"v"}`, + }, { + name: "dangling", + values: makeKV("dangling"), + args: makeKV("k", "v"), + expectKV: `"level"=0 "msg"="msg" "dangling"="" "k"="v"`, + expectJSON: `{"logger":"","level":0,"msg":"msg","dangling":"","k":"v"}`, }} for _, tc := range testCases { - t.Run(tc.name, func(t *testing.T) { - cap := &capture{} - sink := newSink(cap.Func, NewFormatter(Options{})) + t.Run("KV: "+tc.name, func(t *testing.T) { + capt := &capture{} + sink := newSink(capt.Func, NewFormatter(Options{})) + sink = sink.WithValues(tc.values...) + sink.Info(0, "msg", tc.args...) + if capt.log != tc.expectKV { + t.Errorf("\nexpected %q\n got %q", tc.expectKV, capt.log) + } + }) + t.Run("JSON: "+tc.name, func(t *testing.T) { + capt := &capture{} + sink := newSink(capt.Func, NewFormatterJSON(Options{})) sink = sink.WithValues(tc.values...) sink.Info(0, "msg", tc.args...) - if cap.log != tc.expect { - t.Errorf("\nexpected %q\n got %q", tc.expect, cap.log) + if capt.log != tc.expectJSON { + t.Errorf("\nexpected %q\n got %q", tc.expectJSON, capt.log) } }) } @@ -1154,40 +1265,54 @@ func TestInfoWithValues(t *testing.T) { func TestErrorWithValues(t *testing.T) { testCases := []struct { - name string - values []interface{} - args []interface{} - expect string + name string + values []any + args []any + expectKV string + expectJSON string }{{ - name: "zero", - values: makeKV(), - args: makeKV("k", "v"), - expect: ` "msg"="msg" "error"="err" "k"="v"`, - }, { - name: "one", - values: makeKV("one", 1), - args: makeKV("k", "v"), - expect: ` "msg"="msg" "error"="err" "one"=1 "k"="v"`, - }, { - name: "two", - values: makeKV("one", 1, "two", 2), - args: makeKV("k", "v"), - expect: ` "msg"="msg" "error"="err" "one"=1 "two"=2 "k"="v"`, - }, { - name: "dangling", - values: makeKV("dangling"), - args: makeKV("k", "v"), - expect: ` "msg"="msg" "error"="err" "dangling"="" "k"="v"`, + name: "zero", + values: makeKV(), + args: makeKV("k", "v"), + expectKV: `"msg"="msg" "error"="err" "k"="v"`, + expectJSON: `{"logger":"","msg":"msg","error":"err","k":"v"}`, + }, { + name: "one", + values: makeKV("one", 1), + args: makeKV("k", "v"), + expectKV: `"msg"="msg" "error"="err" "one"=1 "k"="v"`, + expectJSON: `{"logger":"","msg":"msg","error":"err","one":1,"k":"v"}`, + }, { + name: "two", + values: makeKV("one", 1, "two", 2), + args: makeKV("k", "v"), + expectKV: `"msg"="msg" "error"="err" "one"=1 "two"=2 "k"="v"`, + expectJSON: `{"logger":"","msg":"msg","error":"err","one":1,"two":2,"k":"v"}`, + }, { + name: "dangling", + values: makeKV("dangling"), + args: makeKV("k", "v"), + expectKV: `"msg"="msg" "error"="err" "dangling"="" "k"="v"`, + expectJSON: `{"logger":"","msg":"msg","error":"err","dangling":"","k":"v"}`, }} for _, tc := range testCases { - t.Run(tc.name, func(t *testing.T) { - cap := &capture{} - sink := newSink(cap.Func, NewFormatter(Options{})) + t.Run("KV: "+tc.name, func(t *testing.T) { + capt := &capture{} + sink := newSink(capt.Func, NewFormatter(Options{})) sink = sink.WithValues(tc.values...) sink.Error(fmt.Errorf("err"), "msg", tc.args...) - if cap.log != tc.expect { - t.Errorf("\nexpected %q\n got %q", tc.expect, cap.log) + if capt.log != tc.expectKV { + t.Errorf("\nexpected %q\n got %q", tc.expectKV, capt.log) + } + }) + t.Run("JSON: "+tc.name, func(t *testing.T) { + capt := &capture{} + sink := newSink(capt.Func, NewFormatterJSON(Options{})) + sink = sink.WithValues(tc.values...) + sink.Error(fmt.Errorf("err"), "msg", tc.args...) + if capt.log != tc.expectJSON { + t.Errorf("\nexpected %q\n got %q", tc.expectJSON, capt.log) } }) } @@ -1195,44 +1320,81 @@ func TestErrorWithValues(t *testing.T) { func TestInfoWithCallDepth(t *testing.T) { t.Run("one", func(t *testing.T) { - cap := &capture{} - sink := newSink(cap.Func, NewFormatter(Options{LogCaller: All})) + capt := &capture{} + sink := newSink(capt.Func, NewFormatter(Options{LogCaller: All})) dSink, _ := sink.(logr.CallDepthLogSink) 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) - if cap.log != expect { - t.Errorf("\nexpected %q\n got %q", expect, cap.log) + 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) } }) } func TestErrorWithCallDepth(t *testing.T) { t.Run("one", func(t *testing.T) { - cap := &capture{} - sink := newSink(cap.Func, NewFormatter(Options{LogCaller: All})) + capt := &capture{} + sink := newSink(capt.Func, NewFormatter(Options{LogCaller: All})) dSink, _ := sink.(logr.CallDepthLogSink) 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) - if cap.log != expect { - t.Errorf("\nexpected %q\n got %q", expect, cap.log) + 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) } }) } func TestOptionsTimestampFormat(t *testing.T) { - cap := &capture{} + capt := &capture{} // This timestamp format contains none of the characters that are // considered placeholders, so will produce a constant result. - sink := newSink(cap.Func, NewFormatter(Options{LogTimestamp: true, TimestampFormat: "TIMESTAMP"})) + sink := newSink(capt.Func, NewFormatter(Options{LogTimestamp: true, TimestampFormat: "TIMESTAMP"})) dSink, _ := sink.(logr.CallDepthLogSink) sink = dSink.WithCallDepth(1) sink.Info(0, "msg") - expect := ` "ts"="TIMESTAMP" "level"=0 "msg"="msg"` - if cap.log != expect { - t.Errorf("\nexpected %q\n got %q", expect, cap.log) + expect := `"ts"="TIMESTAMP" "level"=0 "msg"="msg"` + if capt.log != expect { + 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) + } + }) } } 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..8fb8467 --- /dev/null +++ b/funcr/slogsink_test.go @@ -0,0 +1,234 @@ +//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 ( + "bytes" + "fmt" + "log/slog" + "path/filepath" + "runtime" + "testing" + + "github.com/go-logr/logr" + "github.com/go-logr/logr/internal/testhelp" +) + +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 TestSlogSinkGroups(t *testing.T) { + testCases := []struct { + name string + fn func(slogger *slog.Logger) + expect string + }{{ + name: "no group", + fn: func(slogger *slog.Logger) { + slogger. + Info("msg", "k", "v") + }, + expect: `{"logger":"","level":0,"msg":"msg","k":"v"}`, + }, { + name: "1 group with leaf args", + fn: func(slogger *slog.Logger) { + slogger. + WithGroup("g1"). + Info("msg", "k", "v") + }, + expect: `{"logger":"","level":0,"msg":"msg","g1":{"k":"v"}}`, + }, { + name: "1 group without leaf args", + fn: func(slogger *slog.Logger) { + slogger. + WithGroup("g1"). + Info("msg") + }, + expect: `{"logger":"","level":0,"msg":"msg"}`, + }, { + name: "1 group with value without leaf args", + fn: func(slogger *slog.Logger) { + slogger. + WithGroup("g1").With("k1", 1). + Info("msg") + }, + expect: `{"logger":"","level":0,"msg":"msg","g1":{"k1":1}}`, + }, { + name: "2 groups with values no leaf args", + fn: func(slogger *slog.Logger) { + slogger. + WithGroup("g1").With("k1", 1). + WithGroup("g2").With("k2", 2). + Info("msg") + }, + expect: `{"logger":"","level":0,"msg":"msg","g1":{"k1":1,"g2":{"k2":2}}}`, + }, { + name: "3 empty groups with no values or leaf args", + fn: func(slogger *slog.Logger) { + slogger. + WithGroup("g1"). + WithGroup("g2"). + WithGroup("g3"). + Info("msg") + }, + expect: `{"logger":"","level":0,"msg":"msg"}`, + }, { + name: "3 empty groups with no values but with leaf args", + fn: func(slogger *slog.Logger) { + slogger. + WithGroup("g1"). + WithGroup("g2"). + WithGroup("g3"). + Info("msg", "k", "v") + }, + expect: `{"logger":"","level":0,"msg":"msg","g1":{"g2":{"g3":{"k":"v"}}}}`, + }, { + name: "multiple groups with and without values", + fn: func(slogger *slog.Logger) { + slogger. + With("k0", 0). + WithGroup("g1"). + WithGroup("g2"). + WithGroup("g3").With("k3", 3). + WithGroup("g4"). + WithGroup("g5"). + WithGroup("g6").With("k6", 6). + WithGroup("g7"). + WithGroup("g8"). + WithGroup("g9"). + Info("msg") + }, + expect: `{"logger":"","level":0,"msg":"msg","k0":0,"g1":{"g2":{"g3":{"k3":3,"g4":{"g5":{"g6":{"k6":6}}}}}}}`, + }} + + 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)) + tc.fn(slogger) + if capt.log != tc.expect { + t.Errorf("\nexpected: `%s`\n got: `%s`", tc.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) + } +} + +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(_, _ 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/go.mod b/go.mod index 7baec9b..b4f52a4 100644 --- a/go.mod +++ b/go.mod @@ -1,3 +1,3 @@ module github.com/go-logr/logr -go 1.16 +go 1.18 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/logr.go b/logr.go index e027aea..b4428e1 100644 --- a/logr.go +++ b/logr.go @@ -127,9 +127,9 @@ limitations under the License. // such a value can call its methods without having to check whether the // instance is ready for use. // -// Calling methods with the null logger (Logger{}) as instance will crash -// because it has no LogSink. Therefore this null logger should never be passed -// around. For cases where passing a logger is optional, a pointer to Logger +// The zero logger (= Logger{}) is identical to Discard() and discards all log +// entries. Code that receives a Logger by value can simply call it, the methods +// will never crash. For cases where passing a logger is optional, a pointer to Logger // should be used. // // # Key Naming Conventions @@ -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. @@ -258,6 +254,12 @@ type Logger struct { // Enabled tests whether this Logger is enabled. For example, commandline // flags might be used to set the logging verbosity and disable some info logs. func (l Logger) Enabled() bool { + // Some implementations of LogSink look at the caller in Enabled (e.g. + // different verbosity levels per package or file), but we only pass one + // CallDepth in (via Init). This means that all calls from Logger to the + // LogSink's Enabled, Info, and Error methods must have the same number of + // frames. In other words, Logger methods can't call other Logger methods + // which call these LogSink methods unless we do it the same in all paths. return l.sink != nil && l.sink.Enabled(l.level) } @@ -267,11 +269,11 @@ func (l Logger) Enabled() bool { // line. The key/value pairs can then be used to add additional variable // information. The key/value pairs must alternate string keys and arbitrary // values. -func (l Logger) Info(msg string, keysAndValues ...interface{}) { +func (l Logger) Info(msg string, keysAndValues ...any) { if l.sink == nil { return } - if l.Enabled() { + if l.sink.Enabled(l.level) { // see comment in Enabled if withHelper, ok := l.sink.(CallStackHelperLogSink); ok { withHelper.GetCallStackHelper()() } @@ -289,7 +291,7 @@ func (l Logger) Info(msg string, keysAndValues ...interface{}) { // while the err argument should be used to attach the actual error that // triggered this log line, if present. The err parameter is optional // and nil may be passed instead of an error instance. -func (l Logger) Error(err error, msg string, keysAndValues ...interface{}) { +func (l Logger) Error(err error, msg string, keysAndValues ...any) { if l.sink == nil { return } @@ -314,9 +316,16 @@ func (l Logger) V(level int) Logger { return l } +// GetV returns the verbosity level of the logger. If the logger's LogSink is +// nil as in the Discard logger, this will always return 0. +func (l Logger) GetV() int { + // 0 if l.sink nil because of the if check in V above. + return l.level +} + // WithValues returns a new Logger instance with additional key/value pairs. // See Info for documentation on how key/value pairs work. -func (l Logger) WithValues(keysAndValues ...interface{}) Logger { +func (l Logger) WithValues(keysAndValues ...any) Logger { if l.sink == nil { return l } @@ -397,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 { @@ -467,15 +437,15 @@ type LogSink interface { // The level argument is provided for optional logging. This method will // only be called when Enabled(level) is true. See Logger.Info for more // details. - Info(level int, msg string, keysAndValues ...interface{}) + Info(level int, msg string, keysAndValues ...any) // Error logs an error, with the given message and key/value pairs as // context. See Logger.Error for more details. - Error(err error, msg string, keysAndValues ...interface{}) + Error(err error, msg string, keysAndValues ...any) // WithValues returns a new LogSink with additional key/value pairs. See // Logger.WithValues for more details. - WithValues(keysAndValues ...interface{}) LogSink + WithValues(keysAndValues ...any) LogSink // WithName returns a new LogSink with the specified name appended. See // Logger.WithName for more details. @@ -546,5 +516,5 @@ type Marshaler interface { // with exported fields // // It may return any value of any type. - MarshalLog() interface{} + MarshalLog() any } diff --git a/logr_test.go b/logr_test.go index 00ecf98..7675826 100644 --- a/logr_test.go +++ b/logr_test.go @@ -17,83 +17,13 @@ limitations under the License. package logr import ( - "context" "errors" "fmt" "reflect" + "runtime" "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 ...interface{}) - fnError func(err error, msg string, kv ...interface{}) - fnWithValues func(kv ...interface{}) - fnWithName func(name string) -} - -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 ...interface{}) { - if l.fnInfo != nil { - l.fnInfo(lvl, msg, kv...) - } -} - -func (l *testLogSink) Error(err error, msg string, kv ...interface{}) { - if l.fnError != nil { - l.fnError(err, msg, kv...) - } -} - -func (l *testLogSink) WithValues(kv ...interface{}) LogSink { - if l.fnWithValues != nil { - l.fnWithValues(kv...) - } - out := *l - 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 @@ -130,7 +60,7 @@ func TestEnabled(t *testing.T) { calledEnabled := 0 sink := &testLogSink{} - sink.fnEnabled = func(lvl int) bool { + sink.fnEnabled = func(_ int) bool { calledEnabled++ return true } @@ -148,10 +78,10 @@ func TestError(t *testing.T) { calledError := 0 errInput := fmt.Errorf("error") msgInput := "msg" - kvInput := []interface{}{0, 1, 2} + kvInput := []any{0, 1, 2} sink := &testLogSink{} - sink.fnError = func(err error, msg string, kv ...interface{}) { + sink.fnError = func(err error, msg string, kv ...any) { calledError++ if err != errInput { t.Errorf("unexpected err input, got %v", err) @@ -172,23 +102,53 @@ func TestError(t *testing.T) { } func TestV(t *testing.T) { - sink := &testLogSink{} - logger := New(sink) - - if l := logger.V(0); l.level != 0 { - t.Errorf("expected level 0, got %d", l.level) - } - if l := logger.V(93); l.level != 93 { - t.Errorf("expected level 93, got %d", l.level) - } - if l := logger.V(70).V(6); l.level != 76 { - t.Errorf("expected level 76, got %d", l.level) - } - if l := logger.V(-1); l.level != 0 { - t.Errorf("expected level 0, got %d", l.level) - } - if l := logger.V(1).V(-1); l.level != 1 { - t.Errorf("expected level 1, got %d", l.level) + for name, logger := range map[string]Logger{ + "testLogSink": New(&testLogSink{}), + "Discard": Discard(), + "Zero": {}, + } { + t.Run(name, func(t *testing.T) { + adjust := func(level int) int { + if logger.GetSink() == nil { + // The Discard and the zero Logger short-cut the V call and don't + // change the verbosity level. + return 0 + } + return level + } + inputs := []struct { + name string + fn func() Logger + exp int + }{{ + name: "V(0)", + fn: func() Logger { return logger.V(0) }, + exp: 0, + }, { + name: "V(93)", + fn: func() Logger { return logger.V(93) }, + exp: adjust(93), + }, { + name: "V(70).V(6)", + fn: func() Logger { return logger.V(70).V(6) }, + exp: adjust(76), + }, { + name: "V(-1)", + fn: func() Logger { return logger.V(-1) }, + exp: 0, + }, { + name: "V(1).V(-1)", + fn: func() Logger { return logger.V(1).V(-1) }, + exp: adjust(1), + }} + for _, in := range inputs { + t.Run(in.name, func(t *testing.T) { + if want, got := in.exp, in.fn().GetV(); got != want { + t.Errorf("expected %d, got %d", want, got) + } + }) + } + }) } } @@ -197,14 +157,14 @@ func TestInfo(t *testing.T) { calledInfo := 0 lvlInput := 0 msgInput := "msg" - kvInput := []interface{}{0, 1, 2} + kvInput := []any{0, 1, 2} sink := &testLogSink{} sink.fnEnabled = func(lvl int) bool { calledEnabled++ return lvl < 100 } - sink.fnInfo = func(lvl int, msg string, kv ...interface{}) { + sink.fnInfo = func(lvl int, msg string, kv ...any) { calledInfo++ if lvl != lvlInput { t.Errorf("unexpected lvl input, got %v", lvl) @@ -265,10 +225,10 @@ func TestInfo(t *testing.T) { func TestWithValues(t *testing.T) { calledWithValues := 0 - kvInput := []interface{}{"zero", 0, "one", 1, "two", 2} + kvInput := []any{"zero", 0, "one", 1, "two", 2} sink := &testLogSink{} - sink.fnWithValues = func(kv ...interface{}) { + sink.fnWithValues = func(kv ...any) { calledWithValues++ if !reflect.DeepEqual(kv, kvInput) { t.Errorf("unexpected kv input, got %v", kv) @@ -374,34 +334,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() { @@ -439,3 +371,46 @@ func TestZeroValue(t *testing.T) { l2.Error(errors.New("bar"), "some error") _, _ = l.WithCallStackHelper() } + +func TestCallDepthConsistent(t *testing.T) { + sink := &testLogSink{} + + depth := 0 + expect := "github.com/go-logr/logr.TestCallDepthConsistent" + sink.fnInit = func(ri RuntimeInfo) { + depth = ri.CallDepth + 1 // 1 for these function pointers + if caller := getCaller(depth); caller != expect { + t.Errorf("identified wrong caller %q", caller) + } + + } + sink.fnEnabled = func(_ int) bool { + if caller := getCaller(depth); caller != expect { + t.Errorf("identified wrong caller %q", caller) + } + return true + } + sink.fnError = func(_ error, _ string, _ ...any) { + if caller := getCaller(depth); caller != expect { + t.Errorf("identified wrong caller %q", caller) + } + } + l := New(sink) + + l.Enabled() + l.Info("msg") + l.Error(nil, "msg") +} + +func getCaller(depth int) string { + // +1 for this frame, +1 for Info/Error/Enabled. + pc, _, _, ok := runtime.Caller(depth + 2) + if !ok { + return "" + } + fp := runtime.FuncForPC(pc) + if fp == nil { + return "" + } + return fp.Name() +} diff --git a/sloghandler.go b/sloghandler.go new file mode 100644 index 0000000..82d1ba4 --- /dev/null +++ b/sloghandler.go @@ -0,0 +1,192 @@ +//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" +) + +type slogHandler struct { + // May be nil, in which case all logs get discarded. + sink LogSink + // Non-nil if sink is non-nil and implements SlogSink. + slogSink SlogSink + + // groupPrefix collects values from WithGroup calls. It gets added as + // prefix to value keys when handling a log record. + groupPrefix string + + // levelBias can be set when constructing the handler to influence the + // slog.Level of log records. A positive levelBias reduces the + // slog.Level value. slog has no API to influence this value after the + // handler got created, so it can only be set indirectly through + // Logger.V. + levelBias slog.Level +} + +var _ slog.Handler = &slogHandler{} + +// groupSeparator is used to concatenate WithGroup names and attribute keys. +const groupSeparator = "." + +// GetLevel is used for black box unit testing. +func (l *slogHandler) GetLevel() slog.Level { + return l.levelBias +} + +func (l *slogHandler) Enabled(_ context.Context, level slog.Level) bool { + return l.sink != nil && (level >= slog.LevelError || l.sink.Enabled(l.levelFromSlog(level))) +} + +func (l *slogHandler) Handle(ctx context.Context, record slog.Record) error { + if l.slogSink != nil { + // Only adjust verbosity level of log entries < slog.LevelError. + if record.Level < slog.LevelError { + record.Level -= l.levelBias + } + return l.slogSink.Handle(ctx, record) + } + + // No need to check for nil sink here because Handle will only be called + // when Enabled returned true. + + kvList := make([]any, 0, 2*record.NumAttrs()) + record.Attrs(func(attr slog.Attr) bool { + kvList = attrToKVs(attr, l.groupPrefix, kvList) + return true + }) + if record.Level >= slog.LevelError { + l.sinkWithCallDepth().Error(nil, record.Message, kvList...) + } else { + level := l.levelFromSlog(record.Level) + l.sinkWithCallDepth().Info(level, record.Message, kvList...) + } + return nil +} + +// sinkWithCallDepth adjusts the stack unwinding so that when Error or Info +// are called by Handle, code in slog gets skipped. +// +// This offset currently (Go 1.21.0) works for calls through +// 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 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() LogSink { + if sink, ok := l.sink.(CallDepthLogSink); ok { + return sink.WithCallDepth(2) + } + return l.sink +} + +func (l *slogHandler) WithAttrs(attrs []slog.Attr) slog.Handler { + if l.sink == nil || len(attrs) == 0 { + return l + } + + clone := *l + if l.slogSink != nil { + clone.slogSink = l.slogSink.WithAttrs(attrs) + clone.sink = clone.slogSink + } else { + kvList := make([]any, 0, 2*len(attrs)) + for _, attr := range attrs { + kvList = attrToKVs(attr, l.groupPrefix, kvList) + } + clone.sink = l.sink.WithValues(kvList...) + } + return &clone +} + +func (l *slogHandler) WithGroup(name string) slog.Handler { + if l.sink == nil { + return l + } + if name == "" { + // slog says to inline empty groups + return l + } + clone := *l + if l.slogSink != nil { + clone.slogSink = l.slogSink.WithGroup(name) + clone.sink = clone.slogSink + } else { + clone.groupPrefix = addPrefix(clone.groupPrefix, name) + } + return &clone +} + +// 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 + } + if name == "" { + return prefix + } + return prefix + groupSeparator + name +} + +// 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 *slogHandler) levelFromSlog(level slog.Level) int { + result := -level + result += l.levelBias // in case the original Logger had a V level + if result < 0 { + 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 new file mode 100644 index 0000000..36432c5 --- /dev/null +++ b/slogr/slogr.go @@ -0,0 +1,61 @@ +//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 slogr enables usage of a slog.Handler with logr.Logger as front-end +// API and of a logr.LogSink through the slog.Handler and thus slog.Logger +// APIs. +// +// See the README in the top-level [./logr] package for a discussion of +// interoperability. +// +// Deprecated: use the main logr package instead. +package slogr + +import ( + "log/slog" + + "github.com/go-logr/logr" +) + +// NewLogr returns a logr.Logger which writes to the slog.Handler. +// +// Deprecated: use [logr.FromSlogHandler] instead. +func NewLogr(handler slog.Handler) logr.Logger { + return logr.FromSlogHandler(handler) +} + +// NewSlogHandler returns a slog.Handler which writes to the same sink as the logr.Logger. +// +// Deprecated: use [logr.ToSlogHandler] instead. +func NewSlogHandler(logger logr.Logger) slog.Handler { + return logr.ToSlogHandler(logger) +} + +// ToSlogHandler returns a slog.Handler which writes to the same sink as the logr.Logger. +// +// 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. +// +// Deprecated: use [logr.SlogSink] instead. +type SlogSink = logr.SlogSink diff --git a/slogr_test.go b/slogr_test.go new file mode 100644 index 0000000..91b8302 --- /dev/null +++ b/slogr_test.go @@ -0,0 +1,193 @@ +//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" + "fmt" + "io" + "log/slog" + "os" + "path" + "runtime" + "strings" + "testing" + + "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(_ []string, a slog.Attr) slog.Attr { + if a.Key == "time" { + return slog.Attr{} + } + return a + }, + Level: slog.LevelDebug, +} + +func TestWithCallDepth(t *testing.T) { + debugWithCaller := *debugWithoutTime + debugWithCaller.AddSource = true + var buffer bytes.Buffer + logger := FromSlogHandler(slog.NewTextHandler(&buffer, &debugWithCaller)) + + logHelper := func(logger Logger) { + logger.WithCallDepth(1).Info("hello") + } + + logHelper(logger) + _, file, line, _ := runtime.Caller(0) + expectedSource := fmt.Sprintf("%s:%d", path.Base(file), line-1) + actual := buffer.String() + if !strings.Contains(actual, expectedSource) { + t.Errorf("expected log entry with %s as caller source code location, got instead:\n%s", expectedSource, actual) + } +} + +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 not output groups if there are no attributes", + "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) + 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) { + // Compile-test + logger := slog.New(ToSlogHandler(Discard())) + logger.WithGroup("foo").With("x", 1).Info("hello") +} + +func TestConversion(t *testing.T) { + d := Discard() + d2 := FromSlogHandler(ToSlogHandler(d)) + expectEqual(t, d, d2) + + e := Logger{} + e2 := FromSlogHandler(ToSlogHandler(e)) + expectEqual(t, e, e2) + + text := slog.NewTextHandler(io.Discard, nil) + text2 := ToSlogHandler(FromSlogHandler(text)) + expectEqual(t, text, text2) + + text3 := ToSlogHandler(FromSlogHandler(text).V(1)) + if handler, ok := text3.(interface { + GetLevel() slog.Level + }); ok { + expectEqual(t, handler.GetLevel(), slog.Level(1)) + } else { + t.Errorf("Expected a slogHandler which implements V(1), got instead: %T %+v", text3, text3) + } +} + +func expectEqual(t *testing.T, expected, actual any) { + if expected != actual { + t.Helper() + t.Errorf("Expected %T %+v, got instead: %T %+v", expected, expected, actual, actual) + } +} diff --git a/slogsink.go b/slogsink.go new file mode 100644 index 0000000..4060fcb --- /dev/null +++ b/slogsink.go @@ -0,0 +1,120 @@ +//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" + "runtime" + "time" +) + +var ( + _ LogSink = &slogSink{} + _ CallDepthLogSink = &slogSink{} + _ Underlier = &slogSink{} +) + +// Underlier is implemented by the LogSink returned by NewFromLogHandler. +type Underlier interface { + // GetUnderlying returns the Handler used by the LogSink. + GetUnderlying() slog.Handler +} + +const ( + // nameKey is used to log the `WithName` values as an additional attribute. + nameKey = "logger" + + // errKey is used to log the error parameter of Error as an additional attribute. + errKey = "err" +) + +type slogSink struct { + callDepth int + name string + handler slog.Handler +} + +func (l *slogSink) Init(info RuntimeInfo) { + l.callDepth = info.CallDepth +} + +func (l *slogSink) GetUnderlying() slog.Handler { + return l.handler +} + +func (l *slogSink) WithCallDepth(depth int) LogSink { + newLogger := *l + newLogger.callDepth += depth + return &newLogger +} + +func (l *slogSink) Enabled(level int) bool { + return l.handler.Enabled(context.Background(), slog.Level(-level)) +} + +func (l *slogSink) Info(level int, msg string, kvList ...interface{}) { + l.log(nil, msg, slog.Level(-level), kvList...) +} + +func (l *slogSink) Error(err error, msg string, kvList ...interface{}) { + l.log(err, msg, slog.LevelError, kvList...) +} + +func (l *slogSink) log(err error, msg string, level slog.Level, kvList ...interface{}) { + var pcs [1]uintptr + // skip runtime.Callers, this function, Info/Error, and all helper functions above that. + runtime.Callers(3+l.callDepth, pcs[:]) + + record := slog.NewRecord(time.Now(), level, msg, pcs[0]) + if l.name != "" { + record.AddAttrs(slog.String(nameKey, l.name)) + } + if err != nil { + record.AddAttrs(slog.Any(errKey, err)) + } + record.Add(kvList...) + _ = l.handler.Handle(context.Background(), record) +} + +func (l slogSink) WithName(name string) LogSink { + if l.name != "" { + l.name += "/" + } + l.name += name + return &l +} + +func (l slogSink) WithValues(kvList ...interface{}) LogSink { + l.handler = l.handler.WithAttrs(kvListToAttrs(kvList...)) + return &l +} + +func kvListToAttrs(kvList ...interface{}) []slog.Attr { + // We don't need the record itself, only its Add method. + record := slog.NewRecord(time.Time{}, 0, "", 0) + record.Add(kvList...) + attrs := make([]slog.Attr, 0, record.NumAttrs()) + record.Attrs(func(attr slog.Attr) bool { + attrs = append(attrs, attr) + return true + }) + return attrs +} 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 +} diff --git a/testr/testr.go b/testr/testr.go index 2772b49..5eabe2b 100644 --- a/testr/testr.go +++ b/testr/testr.go @@ -54,7 +54,7 @@ func NewWithOptions(t *testing.T, opts Options) logr.Logger { // TestingT is an interface wrapper around testing.T, testing.B and testing.F. type TestingT interface { Helper() - Log(args ...interface{}) + Log(args ...any) } // NewWithInterface returns a logr.Logger that prints through a @@ -92,7 +92,7 @@ type UnderlierInterface interface { } // Info logging implementation shared between testLogger and testLoggerInterface. -func logInfo(t TestingT, formatInfo func(int, string, []interface{}) (string, string), level int, msg string, kvList ...interface{}) { +func logInfo(t TestingT, formatInfo func(int, string, []any) (string, string), level int, msg string, kvList ...any) { prefix, args := formatInfo(level, msg, kvList) t.Helper() if prefix != "" { @@ -102,7 +102,7 @@ func logInfo(t TestingT, formatInfo func(int, string, []interface{}) (string, st } // Error logging implementation shared between testLogger and testLoggerInterface. -func logError(t TestingT, formatError func(error, string, []interface{}) (string, string), err error, msg string, kvList ...interface{}) { +func logError(t TestingT, formatError func(error, string, []any) (string, string), err error, msg string, kvList ...any) { prefix, args := formatError(err, msg, kvList) t.Helper() if prefix != "" { @@ -134,7 +134,7 @@ func (l testloggerInterface) WithName(name string) logr.LogSink { return &l } -func (l testloggerInterface) WithValues(kvList ...interface{}) logr.LogSink { +func (l testloggerInterface) WithValues(kvList ...any) logr.LogSink { l.Formatter.AddValues(kvList) return &l } @@ -143,12 +143,12 @@ func (l testloggerInterface) GetCallStackHelper() func() { return l.t.Helper } -func (l testloggerInterface) Info(level int, msg string, kvList ...interface{}) { +func (l testloggerInterface) Info(level int, msg string, kvList ...any) { l.t.Helper() logInfo(l.t, l.FormatInfo, level, msg, kvList...) } -func (l testloggerInterface) Error(err error, msg string, kvList ...interface{}) { +func (l testloggerInterface) Error(err error, msg string, kvList ...any) { l.t.Helper() logError(l.t, l.FormatError, err, msg, kvList...) } diff --git a/testr/testr_fuzz_test.go b/testr/testr_fuzz_test.go index d1def0e..ea5217d 100644 --- a/testr/testr_fuzz_test.go +++ b/testr/testr_fuzz_test.go @@ -21,7 +21,7 @@ package testr import "testing" -func TestLoggerTestingF(t *testing.T) { +func TestLoggerTestingF(_ *testing.T) { f := &testing.F{} _ = NewWithInterface(f, Options{}) } diff --git a/testr/testr_test.go b/testr/testr_test.go index 252c4be..01d51fd 100644 --- a/testr/testr_test.go +++ b/testr/testr_test.go @@ -71,7 +71,7 @@ func TestLoggerInterface(t *testing.T) { } } -func TestLoggerTestingB(t *testing.T) { +func TestLoggerTestingB(_ *testing.T) { b := &testing.B{} _ = NewWithInterface(b, Options{}) }