Compare commits

..
4 Commits
Author SHA1 Message Date
sneak 83ad576ed8 Emit slog attributes from every handler (closes #19)
check / check (push) Failing after 20s
check / check (pull_request) Failing after 16s
The handlers took attributes and dropped them on the floor. Handle never
read record.Attrs, so the inline slog.Info("casting", "device", d) form
lost its fields; WithAttrs returned the receiver unchanged, so anything
attached to a derived logger vanished; and WithGroup did the same, so
grouping silently did nothing. The JSON and webhook handlers marshaled
the slog.Record value directly, which cannot work: a record keeps its
attributes in unexported fields, so encoding/json only ever saw Time,
Message, Level and PC.

The consequence was perverse. Converting log.Printf("[%s] Casting %s",
device, file) into structured attributes, as the Go styleguide asks,
left the output with strictly less information than before, and the
calling code reviewed as correct because it was correct.

A small shared attribute layer now holds the accumulated attributes and
open groups. It is copy-on-write, so two loggers derived from one parent
cannot leak attributes into each other, and it qualifies attributes by
the groups open at the time they were attached, per the slog.Handler
contract. Rendering follows each handler's format: the JSON and webhook
handlers emit attributes as object fields with groups as nested objects,
merging a group named twice rather than duplicating its key; the console
handler appends key=value pairs, groups flattened to dotted keys, with
key and value each quoted where leaving it bare would be ambiguous. The
key is quoted as one token, prefix included, so the "=" that separates
the pair is always the first one outside quotes: a key of "a=b" reads as
"a=b"=v rather than as a=b=v, which parses as the key "a" holding the
value "b=v". That is what slog.NewTextHandler does, and the console
rendering was compared against it key by key.

Values the caller logged go into the json payload by reference, because
rendering only reads them, which leaves the group merge as the one place
a value already in the payload is written to. It merges only into the
unexported groupMap type this package allocates for its own groups: a
caller's map[string]any is a different type and can never satisfy that
type assertion, so it is replaced rather than written into. The
invariant holds by construction - nothing reachable from the caller is
modified by logging it.

Values are resolved through slog.Value.Resolve, so LogValuer values are
reported as the value they stand for instead of as a struct, and errors
are reported as their message rather than as the empty object
encoding/json makes of them. Anything encoding/json cannot marshal falls
back to its slog string form rather than rendering as an empty object.

A duration is nanoseconds as a number in the json and webhook payloads,
matching slog.NewJSONHandler, so a consumer can compare and aggregate
the field without parsing it first. The console line keeps the readable
"3s" form, matching slog.NewTextHandler, because a person reads that
one.

The record's own fields keep the names they have always had - Time,
Level, Message, PC - and win a collision with an attribute key, so
existing consumers of the json output see no change beyond the added
fields. That, and a repeated key keeping its last value - except where
both are groups, which merge - are the two ways an attribute can go
missing from the json output; both are now written down in the README,
merge exception included, rather than left to be discovered.

All three handlers are covered, including WebhookHandler, which had the
same defect and is reached through the same MultiplexHandler.

Model: opus-5-5 (rebase)
2026-09-28 09:52:56 +00:00
sneak 76c575642b Add a failing test pinning the discarded slog attributes
Every handler in this package accepts slog attributes and then throws
them away: Handle never reads record.Attrs, and WithAttrs and WithGroup
return the receiver unchanged in ConsoleHandler, JSONHandler and
WebhookHandler alike. So slog.Info("casting", "device", d, "file", f)
emits the message and silently loses both fields, which makes properly
structured logging carry less information than the interpolated
log.Printf calls it replaces.

The test asserts on the bytes the handlers actually write - os.Stdout
for the console and JSON handlers, the posted body for the webhook
handler - rather than on internal state, because the output is where the
loss is observable. It covers record attributes, WithAttrs accumulation,
WithAttrs not mutating its receiver so sibling loggers cannot leak
attributes into each other, WithGroup qualification, slog.Group nesting,
and LogValuer resolution, for each handler and through MultiplexHandler.

It also pins the properties a fix must not get wrong on the way past. A
value the caller logged is read and never written to, even when a group
later claims the same key - for maps and for slices, through the record
path and the derived-logger path, in all three handlers. A duration is
a number of nanoseconds in the json payload and the readable "3s" form
on the console. A console key is quoted on the same terms as a console
value, and as one token including its group prefix, so that the "=" that
separates the pair is always the first one outside quotes: a key of
"a=b" reads as "a=b"=v rather than the ambiguous a=b=v. The four
slog.Handler contract edge cases hold: an empty Attr is ignored, an
empty group is elided with its key, a group with an empty key is
inlined, and WithGroup("") is a no-op. And the two rules that follow
from the json payload being an object hold too: the record's own field
names win a collision, and a repeated key keeps its last value - except
where both are groups, which merge - while the console line keeps both.

This commit adds only the test, and it fails. The fix follows.

Refs: #19

Model: opus-5-5 (rebase)
2026-09-28 09:52:56 +00:00
sneak 64c30e979d Merge pull request 'Update golangci-lint to v2.12.2 with canonical config' (#17) from golangci-v2.12.2 into main
check / check (push) Successful in 47s
Reviewed-on: #17
2026-08-10 15:40:04 +02:00
sneak 403ba4c42e build: update golangci-lint to v2.12.2 with canonical config
check / check (push) Successful in 29s
check / check (pull_request) Successful in 32s
Add the canonical .golangci.yml (v2 schema, all linters enabled with a
small documented disable list) and pin the Dockerfile lint stage to
golangci/golangci-lint:v2.12.2 by tag and digest, replacing the old
v1.64.8 digest-only pin.

Fix all findings surfaced by the v1 to v2 jump without changing any
exported signatures or behavior:

- add package and exported-symbol doc comments (revive)
- rename unused handler parameters to underscore (revive)
- check or explicitly discard error returns (errcheck, errchkjson)
- wrap errors with %w instead of %v (err113)
- use http.NewRequestWithContext instead of http.Post (noctx)
- replace fmt.Println with fmt.Fprintln(os.Stdout, ...) (forbidigo)
- name magic numbers as constants (mnd)
- add explicit slog.LevelDebug case (exhaustive)
- interface{} to any (modernize)
- move tests to the simplelog_test package (testpackage) and add
  t.Parallel() (paralleltest)
- move NewWebhookHandler above its methods (funcorder)
- whitespace, line-length, and blank-line fixes (wsl_v5, whitespace,
  nlreturn, lll, embeddedstructfieldcheck)
- nolint with justification for the intentional init/global design
  (gochecknoinits, gochecknoglobals) and interface-returning
  constructor (ireturn)
2026-08-07 17:10:03 +00:00
15 changed files with 373 additions and 195 deletions
+34
View File
@@ -0,0 +1,34 @@
version: "2"
# Config schema uses the golangci-lint v2 layout (settings live under
# linters.settings, not top-level linters-settings) so that the
# thresholds below are actually applied by golangci-lint >= v2.
run:
timeout: 5m
modules-download-mode: readonly
linters:
default: all
disable:
# Genuinely incompatible with project patterns
- exhaustruct # Requires all struct fields
- depguard # Dependency allow/block lists
- godot # Requires comments to end with periods
- wsl # Deprecated, replaced by wsl_v5
- wrapcheck # Too verbose for internal packages
- varnamelen # Short names like db, id are idiomatic Go
settings:
lll:
line-length: 88
funlen:
lines: 80
statements: 50
cyclop:
max-complexity: 15
dupl:
threshold: 100
issues:
max-issues-per-linter: 0
max-same-issues: 0
+2 -2
View File
@@ -1,6 +1,6 @@
# Lint stage: format check + golangci-lint
# golangci-lint v1.64.8 (2025-02-18)
FROM golangci/golangci-lint@sha256:2987913e27f4eca9c8a39129d2c7bc1e74fbcf77f181e01cea607be437aa5cb8 AS lint
# golangci/golangci-lint:v2.12.2 (Debian-based), 2026-08-07
FROM golangci/golangci-lint:v2.12.2@sha256:5cceeef04e53efe1470638d4b4b4f5ceefd574955ab3941b2d9a68a8c9ad5240 AS lint
WORKDIR /src
COPY go.mod go.sum ./
RUN go mod download
+4
View File
@@ -28,6 +28,10 @@ files it depends on: .golangci.yml, REPO_POLICIES.md, .editorconfig,
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-08-07: added canonical `.golangci.yml` (v2 schema), pinned the
`Dockerfile` lint stage to golangci-lint v2.12.2 (tag+digest), and
fixed all findings the v1→v2 jump surfaced without changing any
exported signatures or behavior
* 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
+27 -2
View File
@@ -25,6 +25,7 @@ func (h handlerAttrs) withAttrs(attrs []slog.Attr) handlerAttrs {
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}
}
@@ -34,9 +35,11 @@ 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}
}
@@ -47,6 +50,7 @@ func (h handlerAttrs) forRecord(record slog.Record) []slog.Attr {
all := make([]slog.Attr, 0, len(h.attrs)+len(own))
all = append(all, h.attrs...)
all = append(all, own...)
return all
}
@@ -58,6 +62,7 @@ func qualifyAttrs(groups []string, attrs []slog.Attr) []slog.Attr {
Value: slog.GroupValue(attrs...),
}}
}
return attrs
}
@@ -68,8 +73,10 @@ 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
}
@@ -96,6 +103,7 @@ func recordToMap(record slog.Record, attrs handlerAttrs) groupMap {
fields["Level"] = record.Level
fields["Message"] = record.Message
fields["PC"] = record.PC
return fields
}
@@ -107,6 +115,7 @@ func attrsToMap(attrs []slog.Attr) groupMap {
for _, attr := range attrs {
addAttrToMap(fields, attr)
}
return fields
}
@@ -135,11 +144,14 @@ func addAttrToMap(fields groupMap, attr slog.Attr) {
nested = make(groupMap, len(group))
fields[attr.Key] = nested
}
target = nested
}
for _, member := range group {
addAttrToMap(target, member)
}
return
}
@@ -173,8 +185,12 @@ func jsonValue(value slog.Value) any {
return value.Duration().Nanoseconds()
case slog.KindTime:
return value.Time()
case slog.KindAny, slog.KindGroup, slog.KindLogValuer:
// Only KindAny arrives here in practice: addAttrToMap renders
// groups itself and resolves every value first.
return jsonAnyValue(value)
default:
// KindAny, and anything a future Go release adds.
// Anything a future Go release adds.
return jsonAnyValue(value)
}
}
@@ -186,9 +202,12 @@ func jsonAnyValue(value slog.Value) any {
return err.Error()
}
}
if _, err := json.Marshal(held); err != nil {
_, err := json.Marshal(held)
if err != nil {
return value.String()
}
return held
}
@@ -204,6 +223,7 @@ func attrsToText(attrs []slog.Attr) string {
for _, attr := range attrs {
appendAttrText(&out, "", attr)
}
return out.String()
}
@@ -218,13 +238,16 @@ func appendAttrText(out *strings.Builder, prefix string, attr slog.Attr) {
if len(group) == 0 {
return
}
nested := prefix
if attr.Key != "" {
nested = prefix + attr.Key + "."
}
for _, member := range group {
appendAttrText(out, nested, member)
}
return
}
@@ -245,11 +268,13 @@ func quoteIfNeeded(text string) string {
if text == "" {
return `""`
}
for _, r := range text {
if unicode.IsSpace(r) || !unicode.IsPrint(r) ||
r == '"' || r == '=' {
return strconv.Quote(text)
}
}
return text
}
+140 -155
View File
@@ -1,4 +1,4 @@
package simplelog
package simplelog_test
import (
"bytes"
@@ -7,13 +7,17 @@ import (
"errors"
"io"
"log/slog"
"maps"
"net/http"
"net/http/httptest"
"os"
"reflect"
"slices"
"strings"
"testing"
"time"
"sneak.berlin/go/simplelog"
)
// These tests assert on the bytes the handlers actually emit, because that is
@@ -22,7 +26,8 @@ import (
// 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.
// this is the only way to see their real output. os.Stdout is shared by the
// whole process, so a test that uses this must not run in parallel.
func captureStdout(t *testing.T, fn func()) string {
t.Helper()
@@ -35,8 +40,10 @@ func captureStdout(t *testing.T, fn func()) string {
os.Stdout = w
collected := make(chan string, 1)
go func() {
var buf bytes.Buffer
_, _ = io.Copy(&buf, r)
collected <- buf.String()
}()
@@ -49,7 +56,9 @@ func captureStdout(t *testing.T, fn func()) string {
fn()
os.Stdout = original
if err := w.Close(); err != nil {
err = w.Close()
if err != nil {
t.Fatalf("close pipe writer: %v", err)
}
@@ -60,9 +69,21 @@ func captureStdout(t *testing.T, fn func()) string {
func testRecord(message string, attrs ...slog.Attr) slog.Record {
record := slog.NewRecord(time.Now(), slog.LevelInfo, message, 0)
record.AddAttrs(attrs...)
return record
}
// handle passes record to handler and fails the test if Handle returns an
// error.
func handle(t *testing.T, handler slog.Handler, record slog.Record) {
t.Helper()
err := handler.Handle(context.Background(), record)
if err != nil {
t.Fatalf("Handle: %v", err)
}
}
// decodeLine parses a single line of JSON handler output.
func decodeLine(t *testing.T, output string) map[string]any {
t.Helper()
@@ -73,9 +94,12 @@ func decodeLine(t *testing.T, output string) map[string]any {
}
var decoded map[string]any
if err := json.Unmarshal([]byte(line), &decoded); err != nil {
err := json.Unmarshal([]byte(line), &decoded)
if err != nil {
t.Fatalf("output is not valid JSON: %v\noutput: %s", err, line)
}
return decoded
}
@@ -87,6 +111,7 @@ func wantField(t *testing.T, decoded map[string]any, key string, want any) {
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)
}
@@ -100,10 +125,12 @@ func wantGroup(t *testing.T, decoded map[string]any, key string) map[string]any
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
}
@@ -156,18 +183,19 @@ func (c castTarget) LogValue() slog.Value {
var _ slog.LogValuer = castTarget{}
// errConnectionRefused is the error the ResolvesValues tests log.
var errConnectionRefused = errors.New("connection refused")
func TestJSONHandlerEmitsRecordAttrs(t *testing.T) {
output := captureStdout(t, func() {
handler := NewJSONHandler()
handler := simplelog.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)
}
handle(t, handler, record)
})
decoded := decodeLine(t, output)
@@ -179,13 +207,11 @@ func TestJSONHandlerEmitsRecordAttrs(t *testing.T) {
func TestJSONHandlerWithAttrsAccumulates(t *testing.T) {
output := captureStdout(t, func() {
handler := NewJSONHandler().
handler := simplelog.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)
}
handle(t, handler, record)
})
decoded := decodeLine(t, output)
@@ -195,43 +221,38 @@ func TestJSONHandlerWithAttrsAccumulates(t *testing.T) {
}
func TestJSONHandlerWithAttrsDoesNotMutateReceiver(t *testing.T) {
parent := NewJSONHandler()
parent := simplelog.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)
}
handle(t, first, testRecord("work"))
})
secondOutput := captureStdout(t, func() {
if err := second.Handle(context.Background(), testRecord("work")); err != nil {
t.Fatalf("Handle: %v", err)
}
handle(t, second, testRecord("work"))
})
parentOutput := captureStdout(t, func() {
if err := parent.Handle(context.Background(), testRecord("work")); err != nil {
t.Fatalf("Handle: %v", err)
}
handle(t, parent, testRecord("work"))
})
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)
t.Fatalf(
"parent handler leaked an attribute from a derived handler: %s",
parentOutput,
)
}
}
func TestJSONHandlerWithGroupNestsAttrs(t *testing.T) {
output := captureStdout(t, func() {
handler := NewJSONHandler().
handler := simplelog.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)
}
handle(t, handler, record)
})
decoded := decodeLine(t, output)
@@ -244,16 +265,14 @@ func TestJSONHandlerWithGroupNestsAttrs(t *testing.T) {
func TestJSONHandlerResolvesValues(t *testing.T) {
output := captureStdout(t, func() {
handler := NewJSONHandler()
handler := simplelog.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")),
slog.Any("error", errConnectionRefused),
)
if err := handler.Handle(context.Background(), record); err != nil {
t.Fatalf("Handle: %v", err)
}
handle(t, handler, record)
})
decoded := decodeLine(t, output)
@@ -267,16 +286,14 @@ func TestJSONHandlerResolvesValues(t *testing.T) {
func TestConsoleHandlerEmitsRecordAttrs(t *testing.T) {
output := captureStdout(t, func() {
handler := NewConsoleHandler()
handler := simplelog.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)
}
handle(t, handler, record)
})
wantContains(t, output, "casting")
@@ -287,11 +304,9 @@ func TestConsoleHandlerEmitsRecordAttrs(t *testing.T) {
func TestConsoleHandlerQuotesValuesNeedingIt(t *testing.T) {
output := captureStdout(t, func() {
handler := NewConsoleHandler()
handler := simplelog.NewConsoleHandler()
record := testRecord("casting", slog.String("file", "The Movie.mp4"))
if err := handler.Handle(context.Background(), record); err != nil {
t.Fatalf("Handle: %v", err)
}
handle(t, handler, record)
})
wantContains(t, output, `file="The Movie.mp4"`)
@@ -312,42 +327,42 @@ func TestConsoleHandlerQuotesKeysNeedingIt(t *testing.T) {
}{
{
name: "an ordinary key is left bare",
build: func() slog.Handler { return NewConsoleHandler() },
build: func() slog.Handler { return simplelog.NewConsoleHandler() },
attrs: []slog.Attr{slog.String("device", "livingroom")},
want: " device=livingroom",
notWant: `"device"`,
},
{
name: "a key containing an equals sign is quoted",
build: func() slog.Handler { return NewConsoleHandler() },
build: func() slog.Handler { return simplelog.NewConsoleHandler() },
attrs: []slog.Attr{slog.String("a=b", "v2")},
want: ` "a=b"=v2`,
notWant: " a=b=v2",
},
{
name: "a key containing a space is quoted",
build: func() slog.Handler { return NewConsoleHandler() },
build: func() slog.Handler { return simplelog.NewConsoleHandler() },
attrs: []slog.Attr{slog.String("my key", "v")},
want: ` "my key"=v`,
notWant: " my key=v",
},
{
name: "a key containing a quote is escaped",
build: func() slog.Handler { return NewConsoleHandler() },
build: func() slog.Handler { return simplelog.NewConsoleHandler() },
attrs: []slog.Attr{slog.String(`he"llo`, "v")},
want: ` "he\"llo"=v`,
notWant: ` he"llo=v`,
},
{
name: "a printable non-ascii key is left bare",
build: func() slog.Handler { return NewConsoleHandler() },
build: func() slog.Handler { return simplelog.NewConsoleHandler() },
attrs: []slog.Attr{slog.String("キー", "v")},
want: " キー=v",
notWant: `"キー"`,
},
{
name: "a group prefix is quoted together with its key",
build: func() slog.Handler { return NewConsoleHandler() },
build: func() slog.Handler { return simplelog.NewConsoleHandler() },
attrs: []slog.Attr{
slog.Group("grp", slog.String("a=b", "v")),
},
@@ -355,9 +370,9 @@ func TestConsoleHandlerQuotesKeysNeedingIt(t *testing.T) {
notWant: " grp.a=b=v",
},
{
name: "a WithGroup prefix needing quotes quotes the whole key",
name: "a WithGroup prefix needing quotes is quoted with its key",
build: func() slog.Handler {
return NewConsoleHandler().WithGroup("my grp")
return simplelog.NewConsoleHandler().WithGroup("my grp")
},
attrs: []slog.Attr{slog.String("k", "v")},
want: ` "my grp.k"=v`,
@@ -365,7 +380,7 @@ func TestConsoleHandlerQuotesKeysNeedingIt(t *testing.T) {
},
{
name: "an empty key is quoted rather than left as a gap",
build: func() slog.Handler { return NewConsoleHandler() },
build: func() slog.Handler { return simplelog.NewConsoleHandler() },
attrs: []slog.Attr{slog.String("", "v")},
want: ` ""=v`,
notWant: " =v",
@@ -375,11 +390,7 @@ func TestConsoleHandlerQuotesKeysNeedingIt(t *testing.T) {
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)
}
handle(t, test.build(), testRecord("casting", test.attrs...))
})
wantContains(t, output, test.want)
@@ -390,13 +401,11 @@ func TestConsoleHandlerQuotesKeysNeedingIt(t *testing.T) {
func TestConsoleHandlerWithAttrsAccumulates(t *testing.T) {
output := captureStdout(t, func() {
handler := NewConsoleHandler().
handler := simplelog.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)
}
handle(t, handler, record)
})
wantContains(t, output, "service=cattbox")
@@ -405,24 +414,18 @@ func TestConsoleHandlerWithAttrsAccumulates(t *testing.T) {
}
func TestConsoleHandlerWithAttrsDoesNotMutateReceiver(t *testing.T) {
parent := NewConsoleHandler()
parent := simplelog.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)
}
handle(t, first, testRecord("work"))
})
secondOutput := captureStdout(t, func() {
if err := second.Handle(context.Background(), testRecord("work")); err != nil {
t.Fatalf("Handle: %v", err)
}
handle(t, second, testRecord("work"))
})
parentOutput := captureStdout(t, func() {
if err := parent.Handle(context.Background(), testRecord("work")); err != nil {
t.Fatalf("Handle: %v", err)
}
handle(t, parent, testRecord("work"))
})
wantContains(t, firstOutput, "worker=first")
@@ -434,13 +437,11 @@ func TestConsoleHandlerWithAttrsDoesNotMutateReceiver(t *testing.T) {
func TestConsoleHandlerWithGroupQualifiesAttrs(t *testing.T) {
output := captureStdout(t, func() {
handler := NewConsoleHandler().
handler := simplelog.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)
}
handle(t, handler, record)
})
wantContains(t, output, "cast.device=livingroom")
@@ -449,16 +450,14 @@ func TestConsoleHandlerWithGroupQualifiesAttrs(t *testing.T) {
func TestConsoleHandlerResolvesValues(t *testing.T) {
output := captureStdout(t, func() {
handler := NewConsoleHandler()
handler := simplelog.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")),
slog.Any("error", errConnectionRefused),
)
if err := handler.Handle(context.Background(), record); err != nil {
t.Fatalf("Handle: %v", err)
}
handle(t, handler, record)
})
wantContains(t, output, "request.status=502")
@@ -467,29 +466,32 @@ func TestConsoleHandlerResolvesValues(t *testing.T) {
}
func TestWebhookHandlerEmitsAttrs(t *testing.T) {
t.Parallel()
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)
handler, err := simplelog.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)
}
handle(t, withAttrs, record)
var body []byte
select {
@@ -504,15 +506,15 @@ func TestWebhookHandlerEmitsAttrs(t *testing.T) {
}
// TestMultiplexHandlerPassesAttrsThrough guards the composite handler that
// package init installs: attributes must survive the multiplex too.
// package init installs: attributes must survive the multiplex too. It is
// built while stdout is the capture pipe, which is not a terminal, so it
// writes through the JSON handler.
func TestMultiplexHandlerPassesAttrsThrough(t *testing.T) {
output := captureStdout(t, func() {
handler := (&MultiplexHandler{handlers: []ExtendedHandler{NewJSONHandler()}}).
handler := simplelog.NewMultiplexHandler().
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)
}
handle(t, handler, record)
})
decoded := decodeLine(t, output)
@@ -529,20 +531,19 @@ func TestMultiplexHandlerPassesAttrsThrough(t *testing.T) {
func TestJSONHandlerDoesNotMutateCallerMap(t *testing.T) {
caller := map[string]any{"mine": "untouched"}
want := maps.Clone(caller)
output := captureStdout(t, func() {
handler := NewJSONHandler()
handler := simplelog.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)
}
handle(t, handler, record)
})
wantUnchanged(t, "map", caller, map[string]any{"mine": "untouched"})
wantUnchanged(t, "map", caller, want)
// The later attribute wins the key outright, as any repeated key does.
group := wantGroup(t, decodeLine(t, output), "g")
@@ -552,18 +553,17 @@ func TestJSONHandlerDoesNotMutateCallerMap(t *testing.T) {
func TestJSONHandlerDoesNotMutateCallerMapThroughWithAttrs(t *testing.T) {
caller := map[string]any{"id": "req-1"}
want := maps.Clone(caller)
output := captureStdout(t, func() {
handler := NewJSONHandler().
handler := simplelog.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)
}
handle(t, handler, record)
})
wantUnchanged(t, "map", caller, map[string]any{"id": "req-1"})
wantUnchanged(t, "map", caller, want)
group := wantGroup(t, decodeLine(t, output), "req")
wantField(t, group, "status", float64(502))
@@ -579,26 +579,20 @@ func TestJSONHandlerDoesNotMutateCallerSlice(t *testing.T) {
caller := make([]any, 2, 4)
caller[0] = "first"
caller[1] = "second"
backing := slices.Clone(caller[:cap(caller)])
output := captureStdout(t, func() {
handler := NewJSONHandler()
handler := simplelog.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)
}
handle(t, handler, record)
})
wantUnchanged(t, "slice", caller, []any{"first", "second"})
wantUnchanged(
t,
"slice backing array",
caller[:cap(caller)],
[]any{"first", "second", nil, nil},
)
wantUnchanged(t, "slice", caller, backing[:2])
wantUnchanged(t, "slice backing array", caller[:cap(caller)], backing)
group := wantGroup(t, decodeLine(t, output), "s")
wantField(t, group, "injected", float64(1))
@@ -606,40 +600,45 @@ func TestJSONHandlerDoesNotMutateCallerSlice(t *testing.T) {
func TestConsoleHandlerDoesNotMutateCallerMap(t *testing.T) {
caller := map[string]any{"mine": "untouched"}
want := maps.Clone(caller)
output := captureStdout(t, func() {
handler := NewConsoleHandler()
handler := simplelog.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)
}
handle(t, handler, record)
})
wantUnchanged(t, "map", caller, map[string]any{"mine": "untouched"})
wantUnchanged(t, "map", caller, want)
wantContains(t, output, "g.injected=1")
}
func TestWebhookHandlerDoesNotMutateCallerMap(t *testing.T) {
t.Parallel()
caller := map[string]any{"id": "req-1"}
want := maps.Clone(caller)
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)
handler, err := simplelog.NewWebhookHandler(server.URL)
if err != nil {
t.Fatalf("NewWebhookHandler: %v", err)
}
@@ -648,9 +647,7 @@ func TestWebhookHandlerDoesNotMutateCallerMap(t *testing.T) {
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)
}
handle(t, derived, record)
var body []byte
select {
@@ -659,7 +656,7 @@ func TestWebhookHandlerDoesNotMutateCallerMap(t *testing.T) {
t.Fatal("webhook handler posted nothing")
}
wantUnchanged(t, "map", caller, map[string]any{"id": "req-1"})
wantUnchanged(t, "map", caller, want)
group := wantGroup(t, decodeLine(t, string(body)), "req")
wantField(t, group, "status", float64(502))
@@ -671,17 +668,16 @@ func TestWebhookHandlerDoesNotMutateCallerMap(t *testing.T) {
// form would silently arrive as a string.
func TestJSONHandlerRendersDurationAsNanoseconds(t *testing.T) {
output := captureStdout(t, func() {
handler := NewJSONHandler()
handler := simplelog.NewJSONHandler()
record := testRecord("casting", slog.Duration("elapsed", 3*time.Second))
if err := handler.Handle(context.Background(), record); err != nil {
t.Fatalf("Handle: %v", err)
}
handle(t, handler, record)
})
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()))
}
@@ -690,11 +686,9 @@ func TestJSONHandlerRendersDurationAsNanoseconds(t *testing.T) {
// form slog.NewTextHandler uses.
func TestConsoleHandlerRendersDurationReadably(t *testing.T) {
output := captureStdout(t, func() {
handler := NewConsoleHandler()
handler := simplelog.NewConsoleHandler()
record := testRecord("casting", slog.Duration("elapsed", 3*time.Second))
if err := handler.Handle(context.Background(), record); err != nil {
t.Fatalf("Handle: %v", err)
}
handle(t, handler, record)
})
wantContains(t, output, "elapsed=3s")
@@ -716,9 +710,10 @@ func TestJSONHandlerContractEdgeCases(t *testing.T) {
}{
{
name: "empty attr is ignored",
build: func() slog.Handler { return NewJSONHandler() },
build: func() slog.Handler { return simplelog.NewJSONHandler() },
attrs: []slog.Attr{{}, slog.String("kept", "yes")},
verify: func(t *testing.T, decoded map[string]any) {
t.Helper()
wantField(t, decoded, "kept", "yes")
wantNoField(t, decoded, "")
},
@@ -726,22 +721,24 @@ func TestJSONHandlerContractEdgeCases(t *testing.T) {
{
name: "empty group is elided along with its key",
build: func() slog.Handler {
return NewJSONHandler().
return simplelog.NewJSONHandler().
WithAttrs([]slog.Attr{slog.Group("empty")})
},
attrs: []slog.Attr{slog.String("kept", "yes")},
verify: func(t *testing.T, decoded map[string]any) {
t.Helper()
wantField(t, decoded, "kept", "yes")
wantNoField(t, decoded, "empty")
},
},
{
name: "group with an empty key is inlined",
build: func() slog.Handler { return NewJSONHandler() },
build: func() slog.Handler { return simplelog.NewJSONHandler() },
attrs: []slog.Attr{
slog.Group("", slog.String("inner", "yes")),
},
verify: func(t *testing.T, decoded map[string]any) {
t.Helper()
wantField(t, decoded, "inner", "yes")
wantNoField(t, decoded, "")
},
@@ -749,10 +746,11 @@ func TestJSONHandlerContractEdgeCases(t *testing.T) {
{
name: "WithGroup with an empty name is a no-op",
build: func() slog.Handler {
return NewJSONHandler().WithGroup("")
return simplelog.NewJSONHandler().WithGroup("")
},
attrs: []slog.Attr{slog.String("kept", "yes")},
verify: func(t *testing.T, decoded map[string]any) {
t.Helper()
wantField(t, decoded, "kept", "yes")
wantNoField(t, decoded, "")
},
@@ -762,11 +760,7 @@ func TestJSONHandlerContractEdgeCases(t *testing.T) {
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)
}
handle(t, test.build(), testRecord("casting", test.attrs...))
})
test.verify(t, decodeLine(t, output))
@@ -786,7 +780,7 @@ func TestConsoleHandlerContractEdgeCases(t *testing.T) {
}{
{
name: "empty attr is ignored",
build: func() slog.Handler { return NewConsoleHandler() },
build: func() slog.Handler { return simplelog.NewConsoleHandler() },
attrs: []slog.Attr{{}, slog.String("kept", "yes")},
want: "kept=yes",
notWant: " =",
@@ -794,7 +788,7 @@ func TestConsoleHandlerContractEdgeCases(t *testing.T) {
{
name: "empty group is elided along with its key",
build: func() slog.Handler {
return NewConsoleHandler().
return simplelog.NewConsoleHandler().
WithAttrs([]slog.Attr{slog.Group("empty")})
},
attrs: []slog.Attr{slog.String("kept", "yes")},
@@ -803,7 +797,7 @@ func TestConsoleHandlerContractEdgeCases(t *testing.T) {
},
{
name: "group with an empty key is inlined",
build: func() slog.Handler { return NewConsoleHandler() },
build: func() slog.Handler { return simplelog.NewConsoleHandler() },
attrs: []slog.Attr{
slog.Group("", slog.String("inner", "yes")),
},
@@ -813,7 +807,7 @@ func TestConsoleHandlerContractEdgeCases(t *testing.T) {
{
name: "WithGroup with an empty name is a no-op",
build: func() slog.Handler {
return NewConsoleHandler().WithGroup("")
return simplelog.NewConsoleHandler().WithGroup("")
},
attrs: []slog.Attr{slog.String("kept", "yes")},
want: " kept=yes",
@@ -824,11 +818,7 @@ func TestConsoleHandlerContractEdgeCases(t *testing.T) {
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)
}
handle(t, test.build(), testRecord("casting", test.attrs...))
})
wantContains(t, output, test.want)
@@ -842,7 +832,7 @@ func TestConsoleHandlerContractEdgeCases(t *testing.T) {
// and an attribute keyed after one of them is dropped rather than emitted.
func TestJSONHandlerRecordFieldsWinKeyCollision(t *testing.T) {
output := captureStdout(t, func() {
handler := NewJSONHandler()
handler := simplelog.NewJSONHandler()
record := testRecord(
"the real message",
slog.String("Time", "hijacked"),
@@ -851,15 +841,14 @@ func TestJSONHandlerRecordFieldsWinKeyCollision(t *testing.T) {
slog.String("PC", "hijacked"),
slog.String("kept", "yes"),
)
if err := handler.Handle(context.Background(), record); err != nil {
t.Fatalf("Handle: %v", err)
}
handle(t, handler, record)
})
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)
@@ -871,15 +860,13 @@ func TestJSONHandlerRecordFieldsWinKeyCollision(t *testing.T) {
// payload being an object: a key logged twice collapses to its last value.
func TestJSONHandlerDuplicateKeysKeepLast(t *testing.T) {
output := captureStdout(t, func() {
handler := NewJSONHandler()
handler := simplelog.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)
}
handle(t, handler, record)
})
wantField(t, decodeLine(t, output), "device", "livingroom")
@@ -889,15 +876,13 @@ func TestJSONHandlerDuplicateKeysKeepLast(t *testing.T) {
// text is not an object, so both pairs survive there.
func TestConsoleHandlerKeepsDuplicateKeys(t *testing.T) {
output := captureStdout(t, func() {
handler := NewConsoleHandler()
handler := simplelog.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)
}
handle(t, handler, record)
})
wantContains(t, output, "device=kitchen")
+6 -2
View File
@@ -1,3 +1,5 @@
// Command example demonstrates logging through simplelog's default
// slog handler.
package main
import (
@@ -6,13 +8,15 @@ import (
_ "sneak.berlin/go/simplelog"
)
func main() {
// attemptNumber is the example login attempt count logged below.
const attemptNumber = 3
func main() {
// log structured data with slog as usual:
slog.Info(
"User login attempt",
slog.String("user", "JohnDoe"),
slog.Int("attempt", 3),
slog.Int("attempt", attemptNumber),
)
slog.Warn(
"Configuration mismatch",
+30 -6
View File
@@ -4,28 +4,41 @@ import (
"context"
"fmt"
"log/slog"
"os"
"runtime"
"time"
"github.com/fatih/color"
)
// callerSkipFrames is the number of stack frames between runtime.Caller
// and the slog call site that produced the record.
const callerSkipFrames = 4
// ConsoleHandler writes human-readable, colored log lines to stdout.
type ConsoleHandler struct {
attrs handlerAttrs
}
// NewConsoleHandler returns a new ConsoleHandler.
func NewConsoleHandler() *ConsoleHandler {
return &ConsoleHandler{}
}
// Handle writes the record to stdout as a colored, timestamped line
// including the caller file and line, followed by the attributes as
// key=value pairs.
func (c *ConsoleHandler) Handle(
ctx context.Context,
_ context.Context,
record slog.Record,
) error {
timestamp := time.Now().UTC().Format("2006-01-02T15:04:05.000Z07:00")
var colorFunc func(format string, a ...interface{}) string
var colorFunc func(format string, a ...any) string
switch record.Level {
case slog.LevelDebug:
colorFunc = color.New(color.FgWhite).SprintfFunc()
case slog.LevelInfo:
colorFunc = color.New(color.FgBlue).SprintfFunc()
case slog.LevelWarn:
@@ -37,12 +50,14 @@ func (c *ConsoleHandler) Handle(
}
// Get the caller information
_, file, line, ok := runtime.Caller(4)
_, file, line, ok := runtime.Caller(callerSkipFrames)
if !ok {
file = "???"
line = 0
}
fmt.Println(
_, _ = fmt.Fprintln(
os.Stdout,
colorFunc(
"%s [%s] %s:%d: %s%s",
timestamp,
@@ -53,26 +68,35 @@ func (c *ConsoleHandler) Handle(
attrsToText(c.attrs.forRecord(record)),
),
)
return nil
}
// Enabled reports whether the handler processes records at the given
// level; it always returns true.
func (c *ConsoleHandler) Enabled(
ctx context.Context,
level slog.Level,
_ context.Context,
_ slog.Level,
) bool {
return true
}
// WithAttrs returns a new handler that also emits attrs, qualified by the
// groups open now. The receiver is not modified.
func (c *ConsoleHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
if len(attrs) == 0 {
return c
}
return &ConsoleHandler{attrs: c.attrs.withAttrs(attrs)}
}
// WithGroup returns a new handler that qualifies later attributes with
// the group name. An empty name returns the receiver.
func (c *ConsoleHandler) WithGroup(name string) slog.Handler {
if name == "" {
return c
}
return &ConsoleHandler{attrs: c.attrs.withGroup(name)}
}
+4
View File
@@ -7,6 +7,8 @@ import (
"github.com/google/uuid"
)
// Event is a single structured log entry with a unique ID and
// timestamp.
type Event struct {
ID uuid.UUID `json:"id"`
Timestamp time.Time `json:"timestamp"`
@@ -15,6 +17,8 @@ type Event struct {
Data json.RawMessage `json:"data"`
}
// NewEvent returns an Event with a fresh ID and the current UTC
// timestamp.
func NewEvent(level, message string, data json.RawMessage) Event {
return Event{
ID: uuid.New(),
+1 -1
View File
@@ -2,7 +2,7 @@ package simplelog
import "log/slog"
// Handler defines the interface for different log outputs.
// ExtendedHandler defines the interface for different log outputs.
type ExtendedHandler interface {
slog.Handler
}
+18 -4
View File
@@ -8,37 +8,51 @@ import (
"os"
)
// JSONHandler writes each log record to stdout as a JSON document.
type JSONHandler struct {
attrs handlerAttrs
}
// NewJSONHandler returns a new JSONHandler.
func NewJSONHandler() *JSONHandler {
return &JSONHandler{}
}
func (j *JSONHandler) Handle(ctx context.Context, record slog.Record) error {
// Handle marshals the record, with its attributes, to one JSON object and
// writes it to stdout.
func (j *JSONHandler) Handle(_ context.Context, record slog.Record) error {
jsonData, err := json.Marshal(recordToMap(record, j.attrs))
if err != nil {
return fmt.Errorf("error marshaling log record: %w", err)
return err
}
fmt.Fprintln(os.Stdout, string(jsonData))
_, _ = fmt.Fprintln(os.Stdout, string(jsonData))
return nil
}
func (j *JSONHandler) Enabled(ctx context.Context, level slog.Level) bool {
// Enabled reports whether the handler processes records at the given
// level; it always returns true.
func (j *JSONHandler) Enabled(_ context.Context, _ slog.Level) bool {
return true
}
// WithAttrs returns a new handler that also emits attrs, qualified by the
// groups open now. The receiver is not modified.
func (j *JSONHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
if len(attrs) == 0 {
return j
}
return &JSONHandler{attrs: j.attrs.withAttrs(attrs)}
}
// WithGroup returns a new handler that nests later attributes in an
// object named after the group. An empty name returns the receiver.
func (j *JSONHandler) WithGroup(name string) slog.Handler {
if name == "" {
return j
}
return &JSONHandler{attrs: j.attrs.withGroup(name)}
}
+7 -2
View File
@@ -1,22 +1,27 @@
package simplelog
package simplelog_test
import (
"log/slog"
"testing"
"time"
"sneak.berlin/go/simplelog"
)
// 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()
t.Parallel()
handler := simplelog.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() …
+41 -7
View File
@@ -1,3 +1,7 @@
// Package simplelog installs a multiplexing slog handler as the process
// default on import. It logs human-readable colored output when stdout is
// a terminal, JSON otherwise, and can additionally POST each record to a
// webhook configured via the LOGGER_WEBHOOK_URL environment variable.
package simplelog
import (
@@ -13,23 +17,31 @@ import (
"github.com/mattn/go-isatty"
)
//nolint:gochecknoglobals // webhook destination is read once from the environment
var webhookURL = os.Getenv("LOGGER_WEBHOOK_URL")
//nolint:gochecknoglobals // package-level default logger state is the package's design
var (
webhookURL = os.Getenv("LOGGER_WEBHOOK_URL")
ourCustomLogger *slog.Logger
ourCustomHandler slog.Handler
)
var ourCustomLogger *slog.Logger
var ourCustomHandler slog.Handler
//nolint:gochecknoinits // installs itself as slog default on import by design
func init() {
ourCustomHandler = NewMultiplexHandler()
ourCustomLogger = slog.New(ourCustomHandler)
slog.SetDefault(ourCustomLogger)
}
// MultiplexHandler fans each log record out to a set of underlying
// handlers.
type MultiplexHandler struct {
handlers []ExtendedHandler
}
// NewMultiplexHandler returns a handler that writes colored console
// output when stdout is a terminal and JSON otherwise, plus an optional
// webhook handler when LOGGER_WEBHOOK_URL is set.
func NewMultiplexHandler() slog.Handler {
cl := &MultiplexHandler{}
if isatty.IsTerminal(os.Stdout.Fd()) {
@@ -37,52 +49,69 @@ func NewMultiplexHandler() slog.Handler {
} else {
cl.handlers = append(cl.handlers, NewJSONHandler())
}
if webhookURL != "" {
handler, err := NewWebhookHandler(webhookURL)
if err != nil {
log.Fatalf("Failed to initialize Webhook handler: %v", err)
}
cl.handlers = append(cl.handlers, handler)
}
return cl
}
// Handle forwards the record to every underlying handler, stopping at
// the first error.
func (cl *MultiplexHandler) Handle(
ctx context.Context,
record slog.Record,
) error {
for _, handler := range cl.handlers {
if err := handler.Handle(ctx, record); err != nil {
err := handler.Handle(ctx, record)
if err != nil {
return err
}
}
return nil
}
// Enabled reports whether the handler processes records at the given
// level; it always returns true.
func (cl *MultiplexHandler) Enabled(
ctx context.Context,
level slog.Level,
_ context.Context,
_ slog.Level,
) bool {
// send us all events
return true
}
// WithAttrs returns a new MultiplexHandler whose underlying handlers
// each carry the given attributes.
func (cl *MultiplexHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
newHandlers := make([]ExtendedHandler, len(cl.handlers))
for i, handler := range cl.handlers {
newHandlers[i] = handler.WithAttrs(attrs)
}
return &MultiplexHandler{handlers: newHandlers}
}
// WithGroup returns a new MultiplexHandler whose underlying handlers
// each use the given group name.
func (cl *MultiplexHandler) WithGroup(name string) slog.Handler {
newHandlers := make([]ExtendedHandler, len(cl.handlers))
for i, handler := range cl.handlers {
newHandlers[i] = handler.WithGroup(name)
}
return &MultiplexHandler{handlers: newHandlers}
}
// ExtendedEvent describes an Event augmented with caller file and line
// information.
type ExtendedEvent interface {
GetID() uuid.UUID
GetTimestamp() time.Time
@@ -95,6 +124,7 @@ type ExtendedEvent interface {
type extendedEvent struct {
Event
File string `json:"file"`
Line int `json:"line"`
}
@@ -127,6 +157,10 @@ func (e extendedEvent) GetLine() int {
return e.Line
}
// NewExtendedEvent wraps baseEvent with the caller file and line it was
// logged from.
//
//nolint:ireturn // returning the interface is this constructor's public API
func NewExtendedEvent(baseEvent Event, file string, line int) ExtendedEvent {
return extendedEvent{
Event: baseEvent,
+2 -1
View File
@@ -1,8 +1,9 @@
package simplelog
package simplelog_test
import "testing"
// TestCompile checks if the package compiles successfully.
func TestCompile(t *testing.T) {
t.Parallel()
// This test ensures that the simplelog package compiles without error.
}
+15 -2
View File
@@ -1,3 +1,5 @@
// Command relp_log_trial emits sample log messages through simplelog's
// default slog handler for manual testing.
package main
import (
@@ -6,11 +8,22 @@ import (
_ "sneak.berlin/go/simplelog" // Using underscore to only invoke init()
)
// examplePort is the sample database port logged below.
const examplePort = 5432
func main() {
// Send some test messages with structured data
slog.Info("Starting the application", slog.String("status", "initialized"))
slog.Info("Attempting to connect to database", slog.String("host", "localhost"), slog.Int("port", 5432))
slog.Info(
"Attempting to connect to database",
slog.String("host", "localhost"),
slog.Int("port", examplePort),
)
slog.Warn("Using default configuration", slog.String("configuration", "default"))
slog.Error("Failed to load module", slog.String("module", "finance"), slog.String("error", "module not found"))
slog.Error(
"Failed to load module",
slog.String("module", "finance"),
slog.String("error", "module not found"),
)
slog.Info("Shutting down the application", slog.String("status", "stopped"))
}
+42 -11
View File
@@ -10,51 +10,82 @@ import (
"net/url"
)
// WebhookHandler POSTs each log record as JSON to a configured webhook
// URL.
type WebhookHandler struct {
webhookURL string
attrs handlerAttrs
}
func (w *WebhookHandler) Enabled(ctx context.Context, level slog.Level) bool {
// NewWebhookHandler returns a WebhookHandler that delivers records to
// the given URL, validating the URL first.
func NewWebhookHandler(webhookURL string) (*WebhookHandler, error) {
_, err := url.ParseRequestURI(webhookURL)
if err != nil {
return nil, fmt.Errorf("invalid webhook URL: %w", err)
}
return &WebhookHandler{webhookURL: webhookURL}, nil
}
// Enabled reports whether the handler processes records at the given
// level; it always returns true.
func (w *WebhookHandler) Enabled(_ context.Context, _ slog.Level) bool {
return true
}
// WithAttrs returns a new handler that also emits attrs, qualified by the
// groups open now. The receiver is not modified.
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),
}
}
// WithGroup returns a new handler that nests later attributes in an
// object named after the group. An empty name returns the receiver.
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 {
return nil, fmt.Errorf("invalid webhook URL: %v", err)
}
return &WebhookHandler{webhookURL: webhookURL}, nil
}
// Handle marshals the record, with its attributes, to one JSON object and
// POSTs it to the webhook URL.
func (w *WebhookHandler) Handle(ctx context.Context, record slog.Record) error {
jsonData, err := json.Marshal(recordToMap(record, w.attrs))
if err != nil {
return fmt.Errorf("error marshaling event: %v", err)
return fmt.Errorf("error marshaling event: %w", err)
}
response, err := http.Post(w.webhookURL, "application/json", bytes.NewBuffer(jsonData))
request, err := http.NewRequestWithContext(
ctx,
http.MethodPost,
w.webhookURL,
bytes.NewReader(jsonData),
)
if err != nil {
return fmt.Errorf("error creating webhook request: %w", err)
}
request.Header.Set("Content-Type", "application/json")
response, err := http.DefaultClient.Do(request)
if err != nil {
return err
}
defer response.Body.Close()
defer func() { _ = response.Body.Close() }()
return nil
}