Compare commits
11 Commits
v1.0.0
...
0ebae4b70a
| Author | SHA1 | Date | |
|---|---|---|---|
| 0ebae4b70a | |||
| 5fc919e523 | |||
| 6cb690bfb7 | |||
| 3bd6551c8e | |||
| 403d853d27 | |||
| 4abd40d8e2 | |||
| 9121da9aae | |||
| 74ce052b77 | |||
| 1eef38a5fa | |||
| 97a82e9b2c | |||
|
|
869b7ca4c3 |
12
.gitea/workflows/check.yml
Normal file
12
.gitea/workflows/check.yml
Normal file
@@ -0,0 +1,12 @@
|
||||
name: check
|
||||
|
||||
on:
|
||||
push:
|
||||
pull_request:
|
||||
|
||||
jobs:
|
||||
check:
|
||||
runs-on: ubuntu-latest
|
||||
steps:
|
||||
- uses: actions/checkout@11bd71901bbe5b1630ceea73d27597364c9af683 # v4.2.2
|
||||
- run: docker build .
|
||||
53
Dockerfile
53
Dockerfile
@@ -1,39 +1,20 @@
|
||||
# First stage: Use the golangci-lint image to run the linter
|
||||
FROM golangci/golangci-lint:latest as lint
|
||||
|
||||
# Set the Current Working Directory inside the container
|
||||
WORKDIR /app
|
||||
|
||||
# Copy the go.mod file and the rest of the application code
|
||||
COPY go.mod ./
|
||||
# Lint stage: format check + golangci-lint
|
||||
# golangci-lint v1.64.8 (2025-02-18)
|
||||
FROM golangci/golangci-lint@sha256:2987913e27f4eca9c8a39129d2c7bc1e74fbcf77f181e01cea607be437aa5cb8 AS lint
|
||||
WORKDIR /src
|
||||
COPY go.mod go.sum ./
|
||||
RUN go mod download
|
||||
COPY . .
|
||||
RUN make fmt-check
|
||||
RUN make lint
|
||||
|
||||
# Run golangci-lint
|
||||
RUN golangci-lint run
|
||||
|
||||
RUN sh -c 'test -z "$(gofmt -l .)"'
|
||||
|
||||
# Second stage: Use the official Golang image to run tests
|
||||
FROM golang:1.22 as test
|
||||
|
||||
# Set the Current Working Directory inside the container
|
||||
WORKDIR /app
|
||||
|
||||
# Copy the go.mod file and the rest of the application code
|
||||
COPY go.mod ./
|
||||
# Test stage: run full test suite
|
||||
# golang 1.22.12 (2025-02-04)
|
||||
FROM golang@sha256:1cf6c45ba39db9fd6db16922041d074a63c935556a05c5ccb62d181034df7f02 AS test
|
||||
# Depend on lint stage so both stages always run
|
||||
COPY --from=lint /src/go.sum /dev/null
|
||||
WORKDIR /src
|
||||
COPY go.mod go.sum ./
|
||||
RUN go mod download
|
||||
COPY . .
|
||||
|
||||
# Run tests
|
||||
RUN go test -v ./...
|
||||
|
||||
# Final stage: Combine the linting and testing stages
|
||||
FROM golang:1.22 as final
|
||||
|
||||
# Ensure that the linting stage succeeded
|
||||
WORKDIR /app
|
||||
COPY --from=lint /app .
|
||||
COPY --from=test /app .
|
||||
|
||||
# Set the final CMD to something minimal since we only needed to verify lint and tests during build
|
||||
CMD ["echo", "Build and tests passed successfully!"]
|
||||
|
||||
RUN make test
|
||||
|
||||
17
Makefile
17
Makefile
@@ -1,6 +1,6 @@
|
||||
.PHONY: test
|
||||
.PHONY: test fmt fmt-check lint check docker hooks
|
||||
|
||||
default: test
|
||||
default: check
|
||||
|
||||
test:
|
||||
@go test -v ./...
|
||||
@@ -9,9 +9,20 @@ fmt:
|
||||
goimports -l -w .
|
||||
golangci-lint run --fix
|
||||
|
||||
fmt-check:
|
||||
@test -z "$$(gofmt -l .)" || { echo "gofmt would reformat:"; gofmt -l .; exit 1; }
|
||||
|
||||
lint:
|
||||
golangci-lint run
|
||||
sh -c 'test -z "$$(gofmt -l .)"'
|
||||
|
||||
check: fmt-check lint test
|
||||
|
||||
docker:
|
||||
docker build --progress plain .
|
||||
|
||||
hooks:
|
||||
@echo "Installing git hooks..."
|
||||
@mkdir -p .git/hooks
|
||||
@printf '#!/bin/sh\nmake check\n' > .git/hooks/pre-commit
|
||||
@chmod +x .git/hooks/pre-commit
|
||||
@echo "Pre-commit hook installed."
|
||||
|
||||
41
README.md
41
README.md
@@ -18,6 +18,13 @@ Released v1.0.0 2024-06-14. Works as intended. No known bugs.
|
||||
- if output is a tty, outputs pretty color logs
|
||||
- if output is not a tty, outputs json
|
||||
- supports delivering each log message via a webhook
|
||||
- emits every `slog` attribute: those passed to a log call, those
|
||||
accumulated with `WithAttrs`, and those qualified by `WithGroup`.
|
||||
`slog.Group` values nest, and `slog.LogValuer` values are resolved. In
|
||||
json output attributes are object fields (groups become nested objects);
|
||||
in console output they are appended as `key=value` pairs, with grouped
|
||||
keys written as `group.key=value`. See
|
||||
[Attribute output](#attribute-output) for the details worth knowing
|
||||
|
||||
## Planned Features
|
||||
|
||||
@@ -60,6 +67,40 @@ func main() {
|
||||
}
|
||||
```
|
||||
|
||||
## Attribute output
|
||||
|
||||
Attributes reach every handler: the ones passed to the log call, the ones
|
||||
accumulated with `WithAttrs`, and the ones qualified by the groups open at
|
||||
the time they were attached. `slog.Group` values nest, and
|
||||
`slog.LogValuer` values are resolved to the value they stand for. A few
|
||||
behaviours are worth knowing before you rely on them.
|
||||
|
||||
**Your values are never modified.** Whatever you log is read and rendered,
|
||||
never written to. A map or a slice you pass to `slog.Any` comes back from
|
||||
the logger exactly as you handed it over, even when a group later uses the
|
||||
same key.
|
||||
|
||||
**Durations are nanoseconds in json, and readable on the console.** The
|
||||
json and webhook payloads emit a `slog.Duration` as a number of
|
||||
nanoseconds, matching `slog.NewJSONHandler`, so a consumer can compare and
|
||||
aggregate the field without parsing it. The console line emits the same
|
||||
duration as `3s`, matching `slog.NewTextHandler`, because a person reads
|
||||
it.
|
||||
|
||||
**The json payload is an object, with the consequences an object has.**
|
||||
The record's own fields are named `Time`, `Level`, `Message` and `PC`, and
|
||||
they own those names: an attribute keyed after one of them is dropped from
|
||||
the json and webhook output. A key logged more than once keeps its last
|
||||
value there for the same reason. Neither applies to the console output,
|
||||
which is a line of text: both pairs appear, in order. If you need a field
|
||||
called `message`, pick a key that does not collide - the collision is
|
||||
silent.
|
||||
|
||||
**Empty things follow the `slog.Handler` contract.** An empty `Attr` is
|
||||
ignored, an empty group is elided along with its key, a group with an
|
||||
empty key is inlined into its parent, and `WithGroup("")` returns the
|
||||
handler unchanged.
|
||||
|
||||
## License
|
||||
|
||||
[WTFPL](./LICENSE)
|
||||
|
||||
59
TODO.md
Normal file
59
TODO.md
Normal file
@@ -0,0 +1,59 @@
|
||||
# Workflow
|
||||
|
||||
* branch (from `main`)
|
||||
* do the work in Next Step
|
||||
* move Next Step to the top of Completed Steps
|
||||
* move the top item of Future Steps into Next Step
|
||||
* commit (`TODO.md` changes in the same commit as the work)
|
||||
* merge to `main` if the branch is not protected, otherwise open a PR
|
||||
* push
|
||||
|
||||
# Status
|
||||
|
||||
1.0+
|
||||
|
||||
Tagged v1.0.0 (2024-06-14) and 1.0.1 (2026-02-08). In post-1.0
|
||||
maintenance; the library is referenced by the Go styleguide.
|
||||
|
||||
# Next Step
|
||||
|
||||
Bring the Makefile up to policy in one commit: add fmt-check, check, and
|
||||
hooks targets (test/lint/fmt/docker exist) and add the missing policy
|
||||
files it depends on: .golangci.yml, REPO_POLICIES.md, .editorconfig,
|
||||
.dockerignore, and .gitea/workflows/check.yml running make check.
|
||||
|
||||
# Completed Steps
|
||||
|
||||
* 2026-08-10: fixed every handler discarding slog attributes: console,
|
||||
JSON and webhook handlers now emit record attributes, accumulate
|
||||
WithAttrs without mutating the receiver, and honour WithGroup;
|
||||
slog.Group values nest and LogValuer values are resolved
|
||||
* 2026-02-08: fixed JSONHandler deadlock from recursive log.Println,
|
||||
with regression test; tagged 1.0.1
|
||||
* 2024-06-14: 1.0 prep: lint and fmt enforced in Docker build, call
|
||||
stack depth fix so log locations report correctly, example script,
|
||||
removed non-building RELP code; tagged v1.0.0
|
||||
* 2024-05-22: module path moved to sneak.berlin/go/simplelog
|
||||
* 2024-05-14: initial library: slog-based console, JSON, webhook, and
|
||||
RELP handlers, MultiplexHandler, caller file/line info, UTC ISO
|
||||
timestamps, level-colored output
|
||||
|
||||
# Future Steps
|
||||
|
||||
* Rewrite the Dockerfile to run make check with sha256-pinned base
|
||||
images (currently golangci/golangci-lint:latest and golang:1.22,
|
||||
unpinned, duplicating Makefile logic instead of calling it)
|
||||
* Restructure README.md into the standard sections: Description,
|
||||
Getting Started, Rationale, Design, TODO, License, Author
|
||||
* Delete the old plain TODO file once this TODO.md lands
|
||||
* Add .aider.* to .gitignore and remove the stray aider artifacts from
|
||||
the working tree
|
||||
* Pick one tag scheme before the next release (v1.0.0 vs 1.0.1 are
|
||||
inconsistent)
|
||||
* Tag v1.0.2, with the leading v, once the attribute fix lands, so
|
||||
consuming repos can move off pseudo-version pins in one step
|
||||
* Fix RELP output to cache (from old TODO)
|
||||
* Re-add RELP delivery over TCP to remote rsyslog imrelp; removed
|
||||
2024-06-14 because it did not build (README planned feature)
|
||||
* Add regex filtering for webhook logs (from old TODO)
|
||||
* Better console output format (from old TODO)
|
||||
251
attrs.go
Normal file
251
attrs.go
Normal file
@@ -0,0 +1,251 @@
|
||||
package simplelog
|
||||
|
||||
import (
|
||||
"encoding/json"
|
||||
"log/slog"
|
||||
"strconv"
|
||||
"strings"
|
||||
"unicode"
|
||||
)
|
||||
|
||||
// handlerAttrs is the attribute state every handler carries: the attributes
|
||||
// accumulated by WithAttrs, plus the groups opened by WithGroup. Its methods
|
||||
// never mutate the receiver, so handlers derived from a common parent stay
|
||||
// independent of each other.
|
||||
type handlerAttrs struct {
|
||||
attrs []slog.Attr
|
||||
groups []string
|
||||
}
|
||||
|
||||
// withAttrs returns a copy carrying attrs in addition to those already held.
|
||||
// The attributes are qualified by the groups that are open at the time they
|
||||
// are attached, as the slog.Handler contract requires.
|
||||
func (h handlerAttrs) withAttrs(attrs []slog.Attr) handlerAttrs {
|
||||
qualified := qualifyAttrs(h.groups, attrs)
|
||||
combined := make([]slog.Attr, 0, len(h.attrs)+len(qualified))
|
||||
combined = append(combined, h.attrs...)
|
||||
combined = append(combined, qualified...)
|
||||
return handlerAttrs{attrs: combined, groups: h.groups}
|
||||
}
|
||||
|
||||
// withGroup returns a copy with a further group open. An empty name is a no-op,
|
||||
// per the slog.Handler contract.
|
||||
func (h handlerAttrs) withGroup(name string) handlerAttrs {
|
||||
if name == "" {
|
||||
return h
|
||||
}
|
||||
groups := make([]string, 0, len(h.groups)+1)
|
||||
groups = append(groups, h.groups...)
|
||||
groups = append(groups, name)
|
||||
return handlerAttrs{attrs: h.attrs, groups: groups}
|
||||
}
|
||||
|
||||
// forRecord returns the accumulated attributes followed by the record's own,
|
||||
// the latter qualified by any open groups.
|
||||
func (h handlerAttrs) forRecord(record slog.Record) []slog.Attr {
|
||||
own := qualifyAttrs(h.groups, recordAttrs(record))
|
||||
all := make([]slog.Attr, 0, len(h.attrs)+len(own))
|
||||
all = append(all, h.attrs...)
|
||||
all = append(all, own...)
|
||||
return all
|
||||
}
|
||||
|
||||
// qualifyAttrs nests attrs inside the given open groups, innermost last.
|
||||
func qualifyAttrs(groups []string, attrs []slog.Attr) []slog.Attr {
|
||||
for i := len(groups) - 1; i >= 0; i-- {
|
||||
attrs = []slog.Attr{{
|
||||
Key: groups[i],
|
||||
Value: slog.GroupValue(attrs...),
|
||||
}}
|
||||
}
|
||||
return attrs
|
||||
}
|
||||
|
||||
// recordAttrs collects the attributes a record carries. They live in
|
||||
// unexported fields, so they are only reachable through Record.Attrs - which
|
||||
// is why marshaling a slog.Record directly loses every one of them.
|
||||
func recordAttrs(record slog.Record) []slog.Attr {
|
||||
attrs := make([]slog.Attr, 0, record.NumAttrs())
|
||||
record.Attrs(func(attr slog.Attr) bool {
|
||||
attrs = append(attrs, attr)
|
||||
return true
|
||||
})
|
||||
return attrs
|
||||
}
|
||||
|
||||
// groupMap is a JSON object this package built for itself: the payload of a
|
||||
// record, or one of the nested objects a slog.Group becomes.
|
||||
//
|
||||
// The distinct type is what keeps the handler from writing into data the
|
||||
// caller still owns. A value handed to slog.Any goes into the payload by
|
||||
// reference - copying every logged map and slice would be a real cost for no
|
||||
// gain, since rendering only reads. The one place the handler writes into a
|
||||
// value already in the payload is the group merge below, and a type assertion
|
||||
// to groupMap can only succeed on a map this package allocated: a caller's
|
||||
// map[string]any is a different type and never matches, however it was keyed.
|
||||
// So the invariant holds by construction - nothing reachable from the caller
|
||||
// is ever written to, only read.
|
||||
type groupMap map[string]any
|
||||
|
||||
// recordToMap renders a record, with its handler's attributes, as the JSON
|
||||
// object the JSON and webhook handlers emit. The record's own fields keep the
|
||||
// names they have always had, and win a collision with an attribute key.
|
||||
func recordToMap(record slog.Record, attrs handlerAttrs) groupMap {
|
||||
fields := attrsToMap(attrs.forRecord(record))
|
||||
fields["Time"] = record.Time
|
||||
fields["Level"] = record.Level
|
||||
fields["Message"] = record.Message
|
||||
fields["PC"] = record.PC
|
||||
return fields
|
||||
}
|
||||
|
||||
// attrsToMap renders attributes as a JSON object in which groups are nested
|
||||
// objects. A group named more than once is merged rather than duplicated;
|
||||
// any other repeated key keeps the last value, as a JSON object must.
|
||||
func attrsToMap(attrs []slog.Attr) groupMap {
|
||||
fields := make(groupMap, len(attrs))
|
||||
for _, attr := range attrs {
|
||||
addAttrToMap(fields, attr)
|
||||
}
|
||||
return fields
|
||||
}
|
||||
|
||||
func addAttrToMap(fields groupMap, attr slog.Attr) {
|
||||
value := attr.Value.Resolve()
|
||||
if attr.Key == "" && value.Any() == nil {
|
||||
// An empty Attr is ignored, per the slog.Handler contract.
|
||||
return
|
||||
}
|
||||
|
||||
if value.Kind() == slog.KindGroup {
|
||||
group := value.Group()
|
||||
if len(group) == 0 {
|
||||
// An empty group is elided, as is its key.
|
||||
return
|
||||
}
|
||||
// A group with an empty key is inlined into its parent.
|
||||
target := fields
|
||||
if attr.Key != "" {
|
||||
// Merge only into a group this package built. Anything else
|
||||
// at this key - including a map the caller logged - is
|
||||
// replaced rather than written into, so the caller's own
|
||||
// data structure is never touched.
|
||||
nested, ok := fields[attr.Key].(groupMap)
|
||||
if !ok {
|
||||
nested = make(groupMap, len(group))
|
||||
fields[attr.Key] = nested
|
||||
}
|
||||
target = nested
|
||||
}
|
||||
for _, member := range group {
|
||||
addAttrToMap(target, member)
|
||||
}
|
||||
return
|
||||
}
|
||||
|
||||
fields[attr.Key] = jsonValue(value)
|
||||
}
|
||||
|
||||
// jsonValue converts a resolved slog.Value into something encoding/json can
|
||||
// render usefully. Values it cannot marshal - and errors, which marshal to an
|
||||
// empty object - fall back to their slog string form, so a value is never
|
||||
// rendered as an empty object.
|
||||
//
|
||||
// Values are returned as they were given, not copied: nothing here or in its
|
||||
// callers writes to a value the caller supplied.
|
||||
func jsonValue(value slog.Value) any {
|
||||
switch value.Kind() {
|
||||
case slog.KindString:
|
||||
return value.String()
|
||||
case slog.KindInt64:
|
||||
return value.Int64()
|
||||
case slog.KindUint64:
|
||||
return value.Uint64()
|
||||
case slog.KindFloat64:
|
||||
return value.Float64()
|
||||
case slog.KindBool:
|
||||
return value.Bool()
|
||||
case slog.KindDuration:
|
||||
// Nanoseconds as a number, which is what slog.NewJSONHandler
|
||||
// emits. A JSON consumer can then compare and aggregate the
|
||||
// field; the "3s" form would have to be parsed first, and no
|
||||
// common log pipeline knows how.
|
||||
return value.Duration().Nanoseconds()
|
||||
case slog.KindTime:
|
||||
return value.Time()
|
||||
default:
|
||||
// KindAny, and anything a future Go release adds.
|
||||
return jsonAnyValue(value)
|
||||
}
|
||||
}
|
||||
|
||||
func jsonAnyValue(value slog.Value) any {
|
||||
held := value.Any()
|
||||
if _, ok := held.(json.Marshaler); !ok {
|
||||
if err, ok := held.(error); ok {
|
||||
return err.Error()
|
||||
}
|
||||
}
|
||||
if _, err := json.Marshal(held); err != nil {
|
||||
return value.String()
|
||||
}
|
||||
return held
|
||||
}
|
||||
|
||||
// attrsToText renders attributes as the space separated key=value pairs the
|
||||
// console handler appends to a log line. Groups become dotted key prefixes.
|
||||
//
|
||||
// Values take their slog string form, so a duration reads as "3s" here where
|
||||
// the json output carries nanoseconds as a number. That is the same split the
|
||||
// stdlib makes between slog.NewTextHandler and slog.NewJSONHandler: the
|
||||
// console line is read by a person, the json line by a program.
|
||||
func attrsToText(attrs []slog.Attr) string {
|
||||
var out strings.Builder
|
||||
for _, attr := range attrs {
|
||||
appendAttrText(&out, "", attr)
|
||||
}
|
||||
return out.String()
|
||||
}
|
||||
|
||||
func appendAttrText(out *strings.Builder, prefix string, attr slog.Attr) {
|
||||
value := attr.Value.Resolve()
|
||||
if attr.Key == "" && value.Any() == nil {
|
||||
return
|
||||
}
|
||||
|
||||
if value.Kind() == slog.KindGroup {
|
||||
group := value.Group()
|
||||
if len(group) == 0 {
|
||||
return
|
||||
}
|
||||
nested := prefix
|
||||
if attr.Key != "" {
|
||||
nested = prefix + attr.Key + "."
|
||||
}
|
||||
for _, member := range group {
|
||||
appendAttrText(out, nested, member)
|
||||
}
|
||||
return
|
||||
}
|
||||
|
||||
out.WriteString(" ")
|
||||
out.WriteString(prefix)
|
||||
out.WriteString(attr.Key)
|
||||
out.WriteString("=")
|
||||
out.WriteString(quoteIfNeeded(value.String()))
|
||||
}
|
||||
|
||||
// quoteIfNeeded quotes a value only when leaving it bare would make the
|
||||
// key=value pairs ambiguous, matching how the stdlib text handler reads.
|
||||
func quoteIfNeeded(value string) string {
|
||||
if value == "" {
|
||||
return `""`
|
||||
}
|
||||
for _, r := range value {
|
||||
if unicode.IsSpace(r) || !unicode.IsPrint(r) ||
|
||||
r == '"' || r == '=' {
|
||||
return strconv.Quote(value)
|
||||
}
|
||||
}
|
||||
return value
|
||||
}
|
||||
814
attrs_test.go
Normal file
814
attrs_test.go
Normal file
@@ -0,0 +1,814 @@
|
||||
package simplelog
|
||||
|
||||
import (
|
||||
"bytes"
|
||||
"context"
|
||||
"encoding/json"
|
||||
"errors"
|
||||
"io"
|
||||
"log/slog"
|
||||
"net/http"
|
||||
"net/http/httptest"
|
||||
"os"
|
||||
"reflect"
|
||||
"strings"
|
||||
"testing"
|
||||
"time"
|
||||
)
|
||||
|
||||
// These tests assert on the bytes the handlers actually emit, because that is
|
||||
// where the defect lives: the handlers accept attributes and then throw them
|
||||
// away, so nothing short of reading the output proves they survived.
|
||||
|
||||
// captureStdout redirects os.Stdout for the duration of fn and returns what was
|
||||
// written to it. Both the console and the JSON handler write to os.Stdout, so
|
||||
// this is the only way to see their real output.
|
||||
func captureStdout(t *testing.T, fn func()) string {
|
||||
t.Helper()
|
||||
|
||||
r, w, err := os.Pipe()
|
||||
if err != nil {
|
||||
t.Fatalf("os.Pipe: %v", err)
|
||||
}
|
||||
|
||||
original := os.Stdout
|
||||
os.Stdout = w
|
||||
|
||||
collected := make(chan string, 1)
|
||||
go func() {
|
||||
var buf bytes.Buffer
|
||||
_, _ = io.Copy(&buf, r)
|
||||
collected <- buf.String()
|
||||
}()
|
||||
|
||||
defer func() {
|
||||
os.Stdout = original
|
||||
_ = r.Close()
|
||||
}()
|
||||
|
||||
fn()
|
||||
|
||||
os.Stdout = original
|
||||
if err := w.Close(); err != nil {
|
||||
t.Fatalf("close pipe writer: %v", err)
|
||||
}
|
||||
|
||||
return <-collected
|
||||
}
|
||||
|
||||
// testRecord builds an INFO record carrying the given attributes.
|
||||
func testRecord(message string, attrs ...slog.Attr) slog.Record {
|
||||
record := slog.NewRecord(time.Now(), slog.LevelInfo, message, 0)
|
||||
record.AddAttrs(attrs...)
|
||||
return record
|
||||
}
|
||||
|
||||
// decodeLine parses a single line of JSON handler output.
|
||||
func decodeLine(t *testing.T, output string) map[string]any {
|
||||
t.Helper()
|
||||
|
||||
line := strings.TrimSpace(output)
|
||||
if line == "" {
|
||||
t.Fatal("handler emitted no output")
|
||||
}
|
||||
|
||||
var decoded map[string]any
|
||||
if err := json.Unmarshal([]byte(line), &decoded); err != nil {
|
||||
t.Fatalf("output is not valid JSON: %v\noutput: %s", err, line)
|
||||
}
|
||||
return decoded
|
||||
}
|
||||
|
||||
// wantField asserts that a decoded JSON object has key with the given value.
|
||||
func wantField(t *testing.T, decoded map[string]any, key string, want any) {
|
||||
t.Helper()
|
||||
|
||||
got, ok := decoded[key]
|
||||
if !ok {
|
||||
t.Fatalf("field %q missing from output: %v", key, decoded)
|
||||
}
|
||||
if got != want {
|
||||
t.Fatalf("field %q = %v, want %v", key, got, want)
|
||||
}
|
||||
}
|
||||
|
||||
// wantGroup asserts that a decoded JSON object has key holding a nested object.
|
||||
func wantGroup(t *testing.T, decoded map[string]any, key string) map[string]any {
|
||||
t.Helper()
|
||||
|
||||
got, ok := decoded[key]
|
||||
if !ok {
|
||||
t.Fatalf("group %q missing from output: %v", key, decoded)
|
||||
}
|
||||
group, ok := got.(map[string]any)
|
||||
if !ok {
|
||||
t.Fatalf("field %q = %v, want a nested object", key, got)
|
||||
}
|
||||
return group
|
||||
}
|
||||
|
||||
// wantNoField asserts that a decoded JSON object does not carry key.
|
||||
func wantNoField(t *testing.T, decoded map[string]any, key string) {
|
||||
t.Helper()
|
||||
|
||||
if got, present := decoded[key]; present {
|
||||
t.Fatalf("field %q unexpectedly present as %v: %v", key, got, decoded)
|
||||
}
|
||||
}
|
||||
|
||||
// wantUnchanged asserts that a value the caller still owns was not written to
|
||||
// by the handler. Logging must read what it is handed, never modify it.
|
||||
func wantUnchanged(t *testing.T, what string, got, want any) {
|
||||
t.Helper()
|
||||
|
||||
if !reflect.DeepEqual(got, want) {
|
||||
t.Fatalf("handler mutated the caller's %s: got %v, want %v", what, got, want)
|
||||
}
|
||||
}
|
||||
|
||||
// wantContains asserts that console output contains a fragment.
|
||||
func wantContains(t *testing.T, output, fragment string) {
|
||||
t.Helper()
|
||||
|
||||
if !strings.Contains(output, fragment) {
|
||||
t.Fatalf("output does not contain %q\noutput: %s", fragment, output)
|
||||
}
|
||||
}
|
||||
|
||||
// wantNotContains asserts that console output does not contain a fragment.
|
||||
func wantNotContains(t *testing.T, output, fragment string) {
|
||||
t.Helper()
|
||||
|
||||
if strings.Contains(output, fragment) {
|
||||
t.Fatalf("output unexpectedly contains %q\noutput: %s", fragment, output)
|
||||
}
|
||||
}
|
||||
|
||||
// castTarget is a slog.LogValuer: the handler must resolve it rather than
|
||||
// serialising the struct itself.
|
||||
type castTarget struct {
|
||||
id string
|
||||
}
|
||||
|
||||
func (c castTarget) LogValue() slog.Value {
|
||||
return slog.StringValue(c.id)
|
||||
}
|
||||
|
||||
var _ slog.LogValuer = castTarget{}
|
||||
|
||||
func TestJSONHandlerEmitsRecordAttrs(t *testing.T) {
|
||||
output := captureStdout(t, func() {
|
||||
handler := NewJSONHandler()
|
||||
record := testRecord(
|
||||
"casting",
|
||||
slog.String("device", "livingroom"),
|
||||
slog.String("file", "movie.mp4"),
|
||||
slog.Int("attempt", 3),
|
||||
)
|
||||
if err := handler.Handle(context.Background(), record); err != nil {
|
||||
t.Fatalf("Handle: %v", err)
|
||||
}
|
||||
})
|
||||
|
||||
decoded := decodeLine(t, output)
|
||||
wantField(t, decoded, "Message", "casting")
|
||||
wantField(t, decoded, "device", "livingroom")
|
||||
wantField(t, decoded, "file", "movie.mp4")
|
||||
wantField(t, decoded, "attempt", float64(3))
|
||||
}
|
||||
|
||||
func TestJSONHandlerWithAttrsAccumulates(t *testing.T) {
|
||||
output := captureStdout(t, func() {
|
||||
handler := NewJSONHandler().
|
||||
WithAttrs([]slog.Attr{slog.String("service", "cattbox")}).
|
||||
WithAttrs([]slog.Attr{slog.String("component", "caster")})
|
||||
record := testRecord("casting", slog.String("device", "livingroom"))
|
||||
if err := handler.Handle(context.Background(), record); err != nil {
|
||||
t.Fatalf("Handle: %v", err)
|
||||
}
|
||||
})
|
||||
|
||||
decoded := decodeLine(t, output)
|
||||
wantField(t, decoded, "service", "cattbox")
|
||||
wantField(t, decoded, "component", "caster")
|
||||
wantField(t, decoded, "device", "livingroom")
|
||||
}
|
||||
|
||||
func TestJSONHandlerWithAttrsDoesNotMutateReceiver(t *testing.T) {
|
||||
parent := NewJSONHandler()
|
||||
first := parent.WithAttrs([]slog.Attr{slog.String("worker", "first")})
|
||||
second := parent.WithAttrs([]slog.Attr{slog.String("worker", "second")})
|
||||
|
||||
firstOutput := captureStdout(t, func() {
|
||||
if err := first.Handle(context.Background(), testRecord("work")); err != nil {
|
||||
t.Fatalf("Handle: %v", err)
|
||||
}
|
||||
})
|
||||
secondOutput := captureStdout(t, func() {
|
||||
if err := second.Handle(context.Background(), testRecord("work")); err != nil {
|
||||
t.Fatalf("Handle: %v", err)
|
||||
}
|
||||
})
|
||||
parentOutput := captureStdout(t, func() {
|
||||
if err := parent.Handle(context.Background(), testRecord("work")); err != nil {
|
||||
t.Fatalf("Handle: %v", err)
|
||||
}
|
||||
})
|
||||
|
||||
wantField(t, decodeLine(t, firstOutput), "worker", "first")
|
||||
wantField(t, decodeLine(t, secondOutput), "worker", "second")
|
||||
|
||||
if _, present := decodeLine(t, parentOutput)["worker"]; present {
|
||||
t.Fatalf("parent handler leaked an attribute from a derived handler: %s", parentOutput)
|
||||
}
|
||||
}
|
||||
|
||||
func TestJSONHandlerWithGroupNestsAttrs(t *testing.T) {
|
||||
output := captureStdout(t, func() {
|
||||
handler := NewJSONHandler().
|
||||
WithGroup("cast").
|
||||
WithAttrs([]slog.Attr{slog.String("device", "livingroom")})
|
||||
record := testRecord("casting", slog.String("file", "movie.mp4"))
|
||||
if err := handler.Handle(context.Background(), record); err != nil {
|
||||
t.Fatalf("Handle: %v", err)
|
||||
}
|
||||
})
|
||||
|
||||
decoded := decodeLine(t, output)
|
||||
wantField(t, decoded, "Message", "casting")
|
||||
|
||||
group := wantGroup(t, decoded, "cast")
|
||||
wantField(t, group, "device", "livingroom")
|
||||
wantField(t, group, "file", "movie.mp4")
|
||||
}
|
||||
|
||||
func TestJSONHandlerResolvesValues(t *testing.T) {
|
||||
output := captureStdout(t, func() {
|
||||
handler := NewJSONHandler()
|
||||
record := testRecord(
|
||||
"cast failed",
|
||||
slog.Group("request", slog.Int("status", 502), slog.String("method", "POST")),
|
||||
slog.Any("target", castTarget{id: "chromecast-7"}),
|
||||
slog.Any("error", errors.New("connection refused")),
|
||||
)
|
||||
if err := handler.Handle(context.Background(), record); err != nil {
|
||||
t.Fatalf("Handle: %v", err)
|
||||
}
|
||||
})
|
||||
|
||||
decoded := decodeLine(t, output)
|
||||
wantField(t, decoded, "target", "chromecast-7")
|
||||
wantField(t, decoded, "error", "connection refused")
|
||||
|
||||
group := wantGroup(t, decoded, "request")
|
||||
wantField(t, group, "status", float64(502))
|
||||
wantField(t, group, "method", "POST")
|
||||
}
|
||||
|
||||
func TestConsoleHandlerEmitsRecordAttrs(t *testing.T) {
|
||||
output := captureStdout(t, func() {
|
||||
handler := NewConsoleHandler()
|
||||
record := testRecord(
|
||||
"casting",
|
||||
slog.String("device", "livingroom"),
|
||||
slog.String("file", "movie.mp4"),
|
||||
slog.Int("attempt", 3),
|
||||
)
|
||||
if err := handler.Handle(context.Background(), record); err != nil {
|
||||
t.Fatalf("Handle: %v", err)
|
||||
}
|
||||
})
|
||||
|
||||
wantContains(t, output, "casting")
|
||||
wantContains(t, output, "device=livingroom")
|
||||
wantContains(t, output, "file=movie.mp4")
|
||||
wantContains(t, output, "attempt=3")
|
||||
}
|
||||
|
||||
func TestConsoleHandlerQuotesValuesNeedingIt(t *testing.T) {
|
||||
output := captureStdout(t, func() {
|
||||
handler := NewConsoleHandler()
|
||||
record := testRecord("casting", slog.String("file", "The Movie.mp4"))
|
||||
if err := handler.Handle(context.Background(), record); err != nil {
|
||||
t.Fatalf("Handle: %v", err)
|
||||
}
|
||||
})
|
||||
|
||||
wantContains(t, output, `file="The Movie.mp4"`)
|
||||
}
|
||||
|
||||
func TestConsoleHandlerWithAttrsAccumulates(t *testing.T) {
|
||||
output := captureStdout(t, func() {
|
||||
handler := NewConsoleHandler().
|
||||
WithAttrs([]slog.Attr{slog.String("service", "cattbox")}).
|
||||
WithAttrs([]slog.Attr{slog.String("component", "caster")})
|
||||
record := testRecord("casting", slog.String("device", "livingroom"))
|
||||
if err := handler.Handle(context.Background(), record); err != nil {
|
||||
t.Fatalf("Handle: %v", err)
|
||||
}
|
||||
})
|
||||
|
||||
wantContains(t, output, "service=cattbox")
|
||||
wantContains(t, output, "component=caster")
|
||||
wantContains(t, output, "device=livingroom")
|
||||
}
|
||||
|
||||
func TestConsoleHandlerWithAttrsDoesNotMutateReceiver(t *testing.T) {
|
||||
parent := NewConsoleHandler()
|
||||
first := parent.WithAttrs([]slog.Attr{slog.String("worker", "first")})
|
||||
second := parent.WithAttrs([]slog.Attr{slog.String("worker", "second")})
|
||||
|
||||
firstOutput := captureStdout(t, func() {
|
||||
if err := first.Handle(context.Background(), testRecord("work")); err != nil {
|
||||
t.Fatalf("Handle: %v", err)
|
||||
}
|
||||
})
|
||||
secondOutput := captureStdout(t, func() {
|
||||
if err := second.Handle(context.Background(), testRecord("work")); err != nil {
|
||||
t.Fatalf("Handle: %v", err)
|
||||
}
|
||||
})
|
||||
parentOutput := captureStdout(t, func() {
|
||||
if err := parent.Handle(context.Background(), testRecord("work")); err != nil {
|
||||
t.Fatalf("Handle: %v", err)
|
||||
}
|
||||
})
|
||||
|
||||
wantContains(t, firstOutput, "worker=first")
|
||||
wantNotContains(t, firstOutput, "worker=second")
|
||||
wantContains(t, secondOutput, "worker=second")
|
||||
wantNotContains(t, secondOutput, "worker=first")
|
||||
wantNotContains(t, parentOutput, "worker=")
|
||||
}
|
||||
|
||||
func TestConsoleHandlerWithGroupQualifiesAttrs(t *testing.T) {
|
||||
output := captureStdout(t, func() {
|
||||
handler := NewConsoleHandler().
|
||||
WithGroup("cast").
|
||||
WithAttrs([]slog.Attr{slog.String("device", "livingroom")})
|
||||
record := testRecord("casting", slog.String("file", "movie.mp4"))
|
||||
if err := handler.Handle(context.Background(), record); err != nil {
|
||||
t.Fatalf("Handle: %v", err)
|
||||
}
|
||||
})
|
||||
|
||||
wantContains(t, output, "cast.device=livingroom")
|
||||
wantContains(t, output, "cast.file=movie.mp4")
|
||||
}
|
||||
|
||||
func TestConsoleHandlerResolvesValues(t *testing.T) {
|
||||
output := captureStdout(t, func() {
|
||||
handler := NewConsoleHandler()
|
||||
record := testRecord(
|
||||
"cast failed",
|
||||
slog.Group("request", slog.Int("status", 502)),
|
||||
slog.Any("target", castTarget{id: "chromecast-7"}),
|
||||
slog.Any("error", errors.New("connection refused")),
|
||||
)
|
||||
if err := handler.Handle(context.Background(), record); err != nil {
|
||||
t.Fatalf("Handle: %v", err)
|
||||
}
|
||||
})
|
||||
|
||||
wantContains(t, output, "request.status=502")
|
||||
wantContains(t, output, "target=chromecast-7")
|
||||
wantContains(t, output, `error="connection refused"`)
|
||||
}
|
||||
|
||||
func TestWebhookHandlerEmitsAttrs(t *testing.T) {
|
||||
bodies := make(chan []byte, 1)
|
||||
server := httptest.NewServer(http.HandlerFunc(
|
||||
func(w http.ResponseWriter, r *http.Request) {
|
||||
body, err := io.ReadAll(r.Body)
|
||||
if err != nil {
|
||||
t.Errorf("read webhook body: %v", err)
|
||||
}
|
||||
bodies <- body
|
||||
w.WriteHeader(http.StatusOK)
|
||||
},
|
||||
))
|
||||
defer server.Close()
|
||||
|
||||
handler, err := NewWebhookHandler(server.URL)
|
||||
if err != nil {
|
||||
t.Fatalf("NewWebhookHandler: %v", err)
|
||||
}
|
||||
|
||||
withAttrs := handler.WithAttrs([]slog.Attr{slog.String("service", "cattbox")})
|
||||
record := testRecord("casting", slog.String("device", "livingroom"))
|
||||
if err := withAttrs.Handle(context.Background(), record); err != nil {
|
||||
t.Fatalf("Handle: %v", err)
|
||||
}
|
||||
|
||||
var body []byte
|
||||
select {
|
||||
case body = <-bodies:
|
||||
case <-time.After(5 * time.Second):
|
||||
t.Fatal("webhook handler posted nothing")
|
||||
}
|
||||
|
||||
decoded := decodeLine(t, string(body))
|
||||
wantField(t, decoded, "service", "cattbox")
|
||||
wantField(t, decoded, "device", "livingroom")
|
||||
}
|
||||
|
||||
// TestMultiplexHandlerPassesAttrsThrough guards the composite handler that
|
||||
// package init installs: attributes must survive the multiplex too.
|
||||
func TestMultiplexHandlerPassesAttrsThrough(t *testing.T) {
|
||||
output := captureStdout(t, func() {
|
||||
handler := (&MultiplexHandler{handlers: []ExtendedHandler{NewJSONHandler()}}).
|
||||
WithAttrs([]slog.Attr{slog.String("service", "cattbox")})
|
||||
record := testRecord("casting", slog.String("device", "livingroom"))
|
||||
if err := handler.Handle(context.Background(), record); err != nil {
|
||||
t.Fatalf("Handle: %v", err)
|
||||
}
|
||||
})
|
||||
|
||||
decoded := decodeLine(t, output)
|
||||
wantField(t, decoded, "service", "cattbox")
|
||||
wantField(t, decoded, "device", "livingroom")
|
||||
}
|
||||
|
||||
// A logging library must read the values it is handed and never write to them.
|
||||
// The dangerous shape is a group that shares a key with something the caller
|
||||
// logged by reference: merging the group's members into whatever already sits
|
||||
// at that key would reach straight back into the caller's own data structure.
|
||||
// The next four tests hold every handler to that, through both the record path
|
||||
// and the derived-logger path.
|
||||
|
||||
func TestJSONHandlerDoesNotMutateCallerMap(t *testing.T) {
|
||||
caller := map[string]any{"mine": "untouched"}
|
||||
|
||||
output := captureStdout(t, func() {
|
||||
handler := NewJSONHandler()
|
||||
record := testRecord(
|
||||
"casting",
|
||||
slog.Any("g", caller),
|
||||
slog.Group("g", slog.Int("injected", 1)),
|
||||
)
|
||||
if err := handler.Handle(context.Background(), record); err != nil {
|
||||
t.Fatalf("Handle: %v", err)
|
||||
}
|
||||
})
|
||||
|
||||
wantUnchanged(t, "map", caller, map[string]any{"mine": "untouched"})
|
||||
|
||||
// The later attribute wins the key outright, as any repeated key does.
|
||||
group := wantGroup(t, decodeLine(t, output), "g")
|
||||
wantField(t, group, "injected", float64(1))
|
||||
wantNoField(t, group, "mine")
|
||||
}
|
||||
|
||||
func TestJSONHandlerDoesNotMutateCallerMapThroughWithAttrs(t *testing.T) {
|
||||
caller := map[string]any{"id": "req-1"}
|
||||
|
||||
output := captureStdout(t, func() {
|
||||
handler := NewJSONHandler().
|
||||
WithAttrs([]slog.Attr{slog.Any("req", caller)}).
|
||||
WithGroup("req")
|
||||
record := testRecord("cast failed", slog.Int("status", 502))
|
||||
if err := handler.Handle(context.Background(), record); err != nil {
|
||||
t.Fatalf("Handle: %v", err)
|
||||
}
|
||||
})
|
||||
|
||||
wantUnchanged(t, "map", caller, map[string]any{"id": "req-1"})
|
||||
|
||||
group := wantGroup(t, decodeLine(t, output), "req")
|
||||
wantField(t, group, "status", float64(502))
|
||||
wantNoField(t, group, "id")
|
||||
}
|
||||
|
||||
// TestJSONHandlerDoesNotMutateCallerSlice is the slice form of the same
|
||||
// hazard: a caller's slice is also handed over by reference, and appending
|
||||
// into its spare capacity would be just as visible to the caller as writing
|
||||
// into its map. The slice is built with room to spare so that an append within
|
||||
// capacity cannot hide behind an unchanged length.
|
||||
func TestJSONHandlerDoesNotMutateCallerSlice(t *testing.T) {
|
||||
caller := make([]any, 2, 4)
|
||||
caller[0] = "first"
|
||||
caller[1] = "second"
|
||||
|
||||
output := captureStdout(t, func() {
|
||||
handler := NewJSONHandler()
|
||||
record := testRecord(
|
||||
"casting",
|
||||
slog.Any("s", caller),
|
||||
slog.Group("s", slog.Int("injected", 1)),
|
||||
)
|
||||
if err := handler.Handle(context.Background(), record); err != nil {
|
||||
t.Fatalf("Handle: %v", err)
|
||||
}
|
||||
})
|
||||
|
||||
wantUnchanged(t, "slice", caller, []any{"first", "second"})
|
||||
wantUnchanged(
|
||||
t,
|
||||
"slice backing array",
|
||||
caller[:cap(caller)],
|
||||
[]any{"first", "second", nil, nil},
|
||||
)
|
||||
|
||||
group := wantGroup(t, decodeLine(t, output), "s")
|
||||
wantField(t, group, "injected", float64(1))
|
||||
}
|
||||
|
||||
func TestConsoleHandlerDoesNotMutateCallerMap(t *testing.T) {
|
||||
caller := map[string]any{"mine": "untouched"}
|
||||
|
||||
output := captureStdout(t, func() {
|
||||
handler := NewConsoleHandler()
|
||||
record := testRecord(
|
||||
"casting",
|
||||
slog.Any("g", caller),
|
||||
slog.Group("g", slog.Int("injected", 1)),
|
||||
)
|
||||
if err := handler.Handle(context.Background(), record); err != nil {
|
||||
t.Fatalf("Handle: %v", err)
|
||||
}
|
||||
})
|
||||
|
||||
wantUnchanged(t, "map", caller, map[string]any{"mine": "untouched"})
|
||||
wantContains(t, output, "g.injected=1")
|
||||
}
|
||||
|
||||
func TestWebhookHandlerDoesNotMutateCallerMap(t *testing.T) {
|
||||
caller := map[string]any{"id": "req-1"}
|
||||
|
||||
bodies := make(chan []byte, 1)
|
||||
server := httptest.NewServer(http.HandlerFunc(
|
||||
func(w http.ResponseWriter, r *http.Request) {
|
||||
body, err := io.ReadAll(r.Body)
|
||||
if err != nil {
|
||||
t.Errorf("read webhook body: %v", err)
|
||||
}
|
||||
bodies <- body
|
||||
w.WriteHeader(http.StatusOK)
|
||||
},
|
||||
))
|
||||
defer server.Close()
|
||||
|
||||
handler, err := NewWebhookHandler(server.URL)
|
||||
if err != nil {
|
||||
t.Fatalf("NewWebhookHandler: %v", err)
|
||||
}
|
||||
|
||||
derived := handler.
|
||||
WithAttrs([]slog.Attr{slog.Any("req", caller)}).
|
||||
WithGroup("req")
|
||||
record := testRecord("cast failed", slog.Int("status", 502))
|
||||
if err := derived.Handle(context.Background(), record); err != nil {
|
||||
t.Fatalf("Handle: %v", err)
|
||||
}
|
||||
|
||||
var body []byte
|
||||
select {
|
||||
case body = <-bodies:
|
||||
case <-time.After(5 * time.Second):
|
||||
t.Fatal("webhook handler posted nothing")
|
||||
}
|
||||
|
||||
wantUnchanged(t, "map", caller, map[string]any{"id": "req-1"})
|
||||
|
||||
group := wantGroup(t, decodeLine(t, string(body)), "req")
|
||||
wantField(t, group, "status", float64(502))
|
||||
}
|
||||
|
||||
// TestJSONHandlerRendersDurationAsNanoseconds pins the json rendering of a
|
||||
// duration to a number of nanoseconds, which is what slog.NewJSONHandler
|
||||
// emits. A consumer that sums or compares the field needs a number; the "3s"
|
||||
// form would silently arrive as a string.
|
||||
func TestJSONHandlerRendersDurationAsNanoseconds(t *testing.T) {
|
||||
output := captureStdout(t, func() {
|
||||
handler := NewJSONHandler()
|
||||
record := testRecord("casting", slog.Duration("elapsed", 3*time.Second))
|
||||
if err := handler.Handle(context.Background(), record); err != nil {
|
||||
t.Fatalf("Handle: %v", err)
|
||||
}
|
||||
})
|
||||
|
||||
decoded := decodeLine(t, output)
|
||||
if _, isNumber := decoded["elapsed"].(float64); !isNumber {
|
||||
t.Fatalf("field \"elapsed\" = %#v, want a json number", decoded["elapsed"])
|
||||
}
|
||||
wantField(t, decoded, "elapsed", float64((3 * time.Second).Nanoseconds()))
|
||||
}
|
||||
|
||||
// TestConsoleHandlerRendersDurationReadably is the other half of that choice:
|
||||
// the console line is read by a person, so it carries the same human-readable
|
||||
// form slog.NewTextHandler uses.
|
||||
func TestConsoleHandlerRendersDurationReadably(t *testing.T) {
|
||||
output := captureStdout(t, func() {
|
||||
handler := NewConsoleHandler()
|
||||
record := testRecord("casting", slog.Duration("elapsed", 3*time.Second))
|
||||
if err := handler.Handle(context.Background(), record); err != nil {
|
||||
t.Fatalf("Handle: %v", err)
|
||||
}
|
||||
})
|
||||
|
||||
wantContains(t, output, "elapsed=3s")
|
||||
}
|
||||
|
||||
// TestJSONHandlerContractEdgeCases pins the slog.Handler contract's four
|
||||
// edge cases. Every case carries a control attribute as well, so a handler
|
||||
// that emitted no attributes at all would fail rather than pass by omission.
|
||||
//
|
||||
// The empty group is attached through WithAttrs rather than to the record,
|
||||
// because slog.Record.AddAttrs elides empty groups itself: routed through the
|
||||
// record, the case would never reach the handler at all.
|
||||
func TestJSONHandlerContractEdgeCases(t *testing.T) {
|
||||
tests := []struct {
|
||||
name string
|
||||
build func() slog.Handler
|
||||
attrs []slog.Attr
|
||||
verify func(t *testing.T, decoded map[string]any)
|
||||
}{
|
||||
{
|
||||
name: "empty attr is ignored",
|
||||
build: func() slog.Handler { return NewJSONHandler() },
|
||||
attrs: []slog.Attr{{}, slog.String("kept", "yes")},
|
||||
verify: func(t *testing.T, decoded map[string]any) {
|
||||
wantField(t, decoded, "kept", "yes")
|
||||
wantNoField(t, decoded, "")
|
||||
},
|
||||
},
|
||||
{
|
||||
name: "empty group is elided along with its key",
|
||||
build: func() slog.Handler {
|
||||
return NewJSONHandler().
|
||||
WithAttrs([]slog.Attr{slog.Group("empty")})
|
||||
},
|
||||
attrs: []slog.Attr{slog.String("kept", "yes")},
|
||||
verify: func(t *testing.T, decoded map[string]any) {
|
||||
wantField(t, decoded, "kept", "yes")
|
||||
wantNoField(t, decoded, "empty")
|
||||
},
|
||||
},
|
||||
{
|
||||
name: "group with an empty key is inlined",
|
||||
build: func() slog.Handler { return NewJSONHandler() },
|
||||
attrs: []slog.Attr{
|
||||
slog.Group("", slog.String("inner", "yes")),
|
||||
},
|
||||
verify: func(t *testing.T, decoded map[string]any) {
|
||||
wantField(t, decoded, "inner", "yes")
|
||||
wantNoField(t, decoded, "")
|
||||
},
|
||||
},
|
||||
{
|
||||
name: "WithGroup with an empty name is a no-op",
|
||||
build: func() slog.Handler {
|
||||
return NewJSONHandler().WithGroup("")
|
||||
},
|
||||
attrs: []slog.Attr{slog.String("kept", "yes")},
|
||||
verify: func(t *testing.T, decoded map[string]any) {
|
||||
wantField(t, decoded, "kept", "yes")
|
||||
wantNoField(t, decoded, "")
|
||||
},
|
||||
},
|
||||
}
|
||||
|
||||
for _, test := range tests {
|
||||
t.Run(test.name, func(t *testing.T) {
|
||||
output := captureStdout(t, func() {
|
||||
handler := test.build()
|
||||
record := testRecord("casting", test.attrs...)
|
||||
if err := handler.Handle(context.Background(), record); err != nil {
|
||||
t.Fatalf("Handle: %v", err)
|
||||
}
|
||||
})
|
||||
|
||||
test.verify(t, decodeLine(t, output))
|
||||
})
|
||||
}
|
||||
}
|
||||
|
||||
// TestConsoleHandlerContractEdgeCases holds the console handler to the same
|
||||
// four rules, since it renders attributes through its own code path.
|
||||
func TestConsoleHandlerContractEdgeCases(t *testing.T) {
|
||||
tests := []struct {
|
||||
name string
|
||||
build func() slog.Handler
|
||||
attrs []slog.Attr
|
||||
want string
|
||||
notWant string
|
||||
}{
|
||||
{
|
||||
name: "empty attr is ignored",
|
||||
build: func() slog.Handler { return NewConsoleHandler() },
|
||||
attrs: []slog.Attr{{}, slog.String("kept", "yes")},
|
||||
want: "kept=yes",
|
||||
notWant: " =",
|
||||
},
|
||||
{
|
||||
name: "empty group is elided along with its key",
|
||||
build: func() slog.Handler {
|
||||
return NewConsoleHandler().
|
||||
WithAttrs([]slog.Attr{slog.Group("empty")})
|
||||
},
|
||||
attrs: []slog.Attr{slog.String("kept", "yes")},
|
||||
want: "kept=yes",
|
||||
notWant: "empty=",
|
||||
},
|
||||
{
|
||||
name: "group with an empty key is inlined",
|
||||
build: func() slog.Handler { return NewConsoleHandler() },
|
||||
attrs: []slog.Attr{
|
||||
slog.Group("", slog.String("inner", "yes")),
|
||||
},
|
||||
want: " inner=yes",
|
||||
notWant: ".inner=",
|
||||
},
|
||||
{
|
||||
name: "WithGroup with an empty name is a no-op",
|
||||
build: func() slog.Handler {
|
||||
return NewConsoleHandler().WithGroup("")
|
||||
},
|
||||
attrs: []slog.Attr{slog.String("kept", "yes")},
|
||||
want: " kept=yes",
|
||||
notWant: ".kept=",
|
||||
},
|
||||
}
|
||||
|
||||
for _, test := range tests {
|
||||
t.Run(test.name, func(t *testing.T) {
|
||||
output := captureStdout(t, func() {
|
||||
handler := test.build()
|
||||
record := testRecord("casting", test.attrs...)
|
||||
if err := handler.Handle(context.Background(), record); err != nil {
|
||||
t.Fatalf("Handle: %v", err)
|
||||
}
|
||||
})
|
||||
|
||||
wantContains(t, output, test.want)
|
||||
wantNotContains(t, output, test.notWant)
|
||||
})
|
||||
}
|
||||
}
|
||||
|
||||
// TestJSONHandlerRecordFieldsWinKeyCollision pins a caller-visible surprise:
|
||||
// the json payload is an object, so the record's own fields own their names
|
||||
// and an attribute keyed after one of them is dropped rather than emitted.
|
||||
func TestJSONHandlerRecordFieldsWinKeyCollision(t *testing.T) {
|
||||
output := captureStdout(t, func() {
|
||||
handler := NewJSONHandler()
|
||||
record := testRecord(
|
||||
"the real message",
|
||||
slog.String("Time", "hijacked"),
|
||||
slog.String("Level", "hijacked"),
|
||||
slog.String("Message", "hijacked"),
|
||||
slog.String("PC", "hijacked"),
|
||||
slog.String("kept", "yes"),
|
||||
)
|
||||
if err := handler.Handle(context.Background(), record); err != nil {
|
||||
t.Fatalf("Handle: %v", err)
|
||||
}
|
||||
})
|
||||
|
||||
decoded := decodeLine(t, output)
|
||||
wantField(t, decoded, "kept", "yes")
|
||||
wantField(t, decoded, "Message", "the real message")
|
||||
wantField(t, decoded, "Level", "INFO")
|
||||
for _, reserved := range []string{"Time", "PC"} {
|
||||
if decoded[reserved] == "hijacked" {
|
||||
t.Fatalf("attribute overwrote the record's own %q field: %v", reserved, decoded)
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
// TestJSONHandlerDuplicateKeysKeepLast pins the other consequence of the
|
||||
// payload being an object: a key logged twice collapses to its last value.
|
||||
func TestJSONHandlerDuplicateKeysKeepLast(t *testing.T) {
|
||||
output := captureStdout(t, func() {
|
||||
handler := NewJSONHandler()
|
||||
record := testRecord(
|
||||
"casting",
|
||||
slog.String("device", "kitchen"),
|
||||
slog.String("device", "livingroom"),
|
||||
)
|
||||
if err := handler.Handle(context.Background(), record); err != nil {
|
||||
t.Fatalf("Handle: %v", err)
|
||||
}
|
||||
})
|
||||
|
||||
wantField(t, decodeLine(t, output), "device", "livingroom")
|
||||
}
|
||||
|
||||
// TestConsoleHandlerKeepsDuplicateKeys is the console counterpart: a line of
|
||||
// text is not an object, so both pairs survive there.
|
||||
func TestConsoleHandlerKeepsDuplicateKeys(t *testing.T) {
|
||||
output := captureStdout(t, func() {
|
||||
handler := NewConsoleHandler()
|
||||
record := testRecord(
|
||||
"casting",
|
||||
slog.String("device", "kitchen"),
|
||||
slog.String("device", "livingroom"),
|
||||
)
|
||||
if err := handler.Handle(context.Background(), record); err != nil {
|
||||
t.Fatalf("Handle: %v", err)
|
||||
}
|
||||
})
|
||||
|
||||
wantContains(t, output, "device=kitchen")
|
||||
wantContains(t, output, "device=livingroom")
|
||||
}
|
||||
@@ -10,7 +10,9 @@ import (
|
||||
"github.com/fatih/color"
|
||||
)
|
||||
|
||||
type ConsoleHandler struct{}
|
||||
type ConsoleHandler struct {
|
||||
attrs handlerAttrs
|
||||
}
|
||||
|
||||
func NewConsoleHandler() *ConsoleHandler {
|
||||
return &ConsoleHandler{}
|
||||
@@ -42,12 +44,13 @@ func (c *ConsoleHandler) Handle(
|
||||
}
|
||||
fmt.Println(
|
||||
colorFunc(
|
||||
"%s [%s] %s:%d: %s",
|
||||
"%s [%s] %s:%d: %s%s",
|
||||
timestamp,
|
||||
record.Level,
|
||||
file,
|
||||
line,
|
||||
record.Message,
|
||||
attrsToText(c.attrs.forRecord(record)),
|
||||
),
|
||||
)
|
||||
return nil
|
||||
@@ -61,9 +64,15 @@ func (c *ConsoleHandler) Enabled(
|
||||
}
|
||||
|
||||
func (c *ConsoleHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
|
||||
if len(attrs) == 0 {
|
||||
return c
|
||||
}
|
||||
return &ConsoleHandler{attrs: c.attrs.withAttrs(attrs)}
|
||||
}
|
||||
|
||||
func (c *ConsoleHandler) WithGroup(name string) slog.Handler {
|
||||
if name == "" {
|
||||
return c
|
||||
}
|
||||
return &ConsoleHandler{attrs: c.attrs.withGroup(name)}
|
||||
}
|
||||
|
||||
@@ -3,19 +3,25 @@ package simplelog
|
||||
import (
|
||||
"context"
|
||||
"encoding/json"
|
||||
"log"
|
||||
"fmt"
|
||||
"log/slog"
|
||||
"os"
|
||||
)
|
||||
|
||||
type JSONHandler struct{}
|
||||
type JSONHandler struct {
|
||||
attrs handlerAttrs
|
||||
}
|
||||
|
||||
func NewJSONHandler() *JSONHandler {
|
||||
return &JSONHandler{}
|
||||
}
|
||||
|
||||
func (j *JSONHandler) Handle(ctx context.Context, record slog.Record) error {
|
||||
jsonData, _ := json.Marshal(record)
|
||||
log.Println(string(jsonData))
|
||||
jsonData, err := json.Marshal(recordToMap(record, j.attrs))
|
||||
if err != nil {
|
||||
return fmt.Errorf("error marshaling log record: %w", err)
|
||||
}
|
||||
fmt.Fprintln(os.Stdout, string(jsonData))
|
||||
return nil
|
||||
}
|
||||
|
||||
@@ -24,9 +30,15 @@ func (j *JSONHandler) Enabled(ctx context.Context, level slog.Level) bool {
|
||||
}
|
||||
|
||||
func (j *JSONHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
|
||||
if len(attrs) == 0 {
|
||||
return j
|
||||
}
|
||||
return &JSONHandler{attrs: j.attrs.withAttrs(attrs)}
|
||||
}
|
||||
|
||||
func (j *JSONHandler) WithGroup(name string) slog.Handler {
|
||||
if name == "" {
|
||||
return j
|
||||
}
|
||||
return &JSONHandler{attrs: j.attrs.withGroup(name)}
|
||||
}
|
||||
|
||||
33
json_handler_test.go
Normal file
33
json_handler_test.go
Normal file
@@ -0,0 +1,33 @@
|
||||
package simplelog
|
||||
|
||||
import (
|
||||
"log/slog"
|
||||
"testing"
|
||||
"time"
|
||||
)
|
||||
|
||||
// TestJSONHandlerDeadlock verifies that JSONHandler.Handle does not deadlock
|
||||
// when the default slog handler routes log.Println back through slog.
|
||||
// On the unfixed code this test will hang (deadlock); with the fix it completes.
|
||||
func TestJSONHandlerDeadlock(t *testing.T) {
|
||||
handler := NewJSONHandler()
|
||||
|
||||
// Set our handler as the default so log.Println routes through slog
|
||||
logger := slog.New(handler)
|
||||
slog.SetDefault(logger)
|
||||
|
||||
done := make(chan struct{})
|
||||
go func() {
|
||||
// This call deadlocks on unfixed code because Handle() calls
|
||||
// log.Println() which re-enters slog → Handle() → log.Println() …
|
||||
slog.Info("test message")
|
||||
close(done)
|
||||
}()
|
||||
|
||||
select {
|
||||
case <-done:
|
||||
// success
|
||||
case <-time.After(5 * time.Second):
|
||||
t.Fatal("JSONHandler.Handle deadlocked: timed out after 5 seconds")
|
||||
}
|
||||
}
|
||||
@@ -12,6 +12,7 @@ import (
|
||||
|
||||
type WebhookHandler struct {
|
||||
webhookURL string
|
||||
attrs handlerAttrs
|
||||
}
|
||||
|
||||
func (w *WebhookHandler) Enabled(ctx context.Context, level slog.Level) bool {
|
||||
@@ -19,12 +20,24 @@ func (w *WebhookHandler) Enabled(ctx context.Context, level slog.Level) bool {
|
||||
}
|
||||
|
||||
func (w *WebhookHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
|
||||
if len(attrs) == 0 {
|
||||
return w
|
||||
}
|
||||
return &WebhookHandler{
|
||||
webhookURL: w.webhookURL,
|
||||
attrs: w.attrs.withAttrs(attrs),
|
||||
}
|
||||
}
|
||||
|
||||
func (w *WebhookHandler) WithGroup(name string) slog.Handler {
|
||||
if name == "" {
|
||||
return w
|
||||
}
|
||||
return &WebhookHandler{
|
||||
webhookURL: w.webhookURL,
|
||||
attrs: w.attrs.withGroup(name),
|
||||
}
|
||||
}
|
||||
|
||||
func NewWebhookHandler(webhookURL string) (*WebhookHandler, error) {
|
||||
if _, err := url.ParseRequestURI(webhookURL); err != nil {
|
||||
@@ -34,7 +47,7 @@ func NewWebhookHandler(webhookURL string) (*WebhookHandler, error) {
|
||||
}
|
||||
|
||||
func (w *WebhookHandler) Handle(ctx context.Context, record slog.Record) error {
|
||||
jsonData, err := json.Marshal(record)
|
||||
jsonData, err := json.Marshal(recordToMap(record, w.attrs))
|
||||
if err != nil {
|
||||
return fmt.Errorf("error marshaling event: %v", err)
|
||||
}
|
||||
|
||||
Reference in New Issue
Block a user