Both handlers discard every slog attribute, so structured logging emits less information than the string logging it replaces #19
Reference in New Issue
Block a user
Delete Branch "%!s()"
Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?
Reported by the cattbox manager. Present at upstream
main, not just in the released version, so it is not fixed by the retag in #18.Problem
Both handlers ignore
record.Attrs, and bothWithAttrsimplementations return the receiver unchanged. So:emits the message and silently drops both fields.
Why this is worse than it sounds
CODE_STYLEGUIDE_GO.mdmandates this library org-wide, and the compliance sweep currently under way converts string logging into structured attributes. That conversion looks like this:Before the change, the values were at least present in the message text. After it, they are gone entirely. A repo that correctly follows the styleguide ends up with less information in its logs than it had beforehand — and the code will review as correct, because it is correct. The library throws the data away.
Every repo the sweep converts loses log content this way, invisibly.
Definition of done
record.Attrs— as JSON fields inJSONHandler, in the console format forConsoleHandler.WithAttrsaccumulates rather than returning the receiver, and the accumulated attrs appear on every subsequent record from that logger.WithGroupbehaves per theslog.Handlercontract, or its non-support is documented explicitly rather than silently ignored.v1.0.2, with the leadingv— see #18) so consuming repos can move off pseudo-version pins in one step.Sequencing
#18 first: it is a one-command retag that fixes a production hang. This is a code change and should follow. Consuming repos pinning the pseudo-version get the deadlock fix immediately and can pick this up when it lands.
Tracked downstream as cattbox #24.
Implementation plan
Per the owner's request on sneak/cattbox#24, this
lands as a branch off
mainwith exactly two commits and a normal PR tomain:the bytes the handlers actually emit;
The surface to fix
record.Attrsis only half of it. The full set of places attributes can bedropped:
Handleignoringrecord.Attrs— the inlineslog.Info("casting", "device", d)form. BothJSONHandlerandConsoleHandlerdo this today.WithAttrsreturning the receiver unchanged in both handlers, soattributes attached to a derived logger vanish. It has to return a new
handler and must not mutate the receiver, so two loggers derived from one
parent cannot leak attributes into each other.
WithGroup— also a no-op receiver return today. Same defect wearing adifferent hat.
log/slogdefines the semantics (attrs added afterWithGroupare qualified by the group name), so those get followed ratherthan invented.
WebhookHandler— identical code path (json.Marshal(record),WithAttrsreturning the receiver). It is in the same multiplex, so fixing only two of
three handlers would leave the same bug live for webhook users.
slog.Valueresolution:LogValuervalues must beResolve()d ratherthan serialised as a struct, and
slog.Groupvalues must nest.Approach
Stdlib only, no new dependency (
log/slog+encoding/json; consistent withthe recorded Go package defaults). A small shared attribute layer:
WithAttrsare wrapped in the currently-openWithGroupgroups at the time they are attached, then stored on a copy ofthe handler;
JSONHandler/WebhookHandlerthey render into amap[string]anywithgroups as nested objects, merged recursively so a group opened twice does
not produce a duplicate key, then handed to
encoding/json;ConsoleHandlerthey render askey=valuepairs appended to the line,groups flattened to dotted keys (
group.key=value), quoted only when thevalue needs it.
The JSON top-level keys currently emitted (
Time,Level,Message,PC)stay exactly as they are so existing consumers do not break; attributes join
them as sibling fields, and the record's own fields win a key collision.
Tests
Real emitted output, captured by redirecting
os.Stdoutthrough a pipe (and anhttptestserver for the webhook handler) — not assertions on internal state.Separate assertions per handler, since the two output formats differ. Covered:
record attrs,
WithAttrsaccumulation, sibling non-leakage,WithGroupnesting,
slog.Groupvalues, andLogValuerresolution.Verification
Repo tooling only:
make testwhile iterating, andmake dockerfor the fullcontainerised
fmt-check+lint+testat the branch head. Commit 1 will bechecked out alone to capture its real failure output for the PR body.
Out of scope, not touched: the retag in
#18, and the lint bump in
#17.
Built and pushed as #21, two commits
against
mainin the shape requested onsneak/cattbox#24:
8c3ab23843f1c1bbccd3da273331bb337a1e3caa— addsattrs_test.go, 13 teststhat fail against the current code.
412eed0d54550ecec53020a40a834cbf432e2f32— the fix. No assertion from thefirst commit was touched.
Against the definition of done
record.Attrs.JSONHandleremits them asjson object fields;
ConsoleHandlerappends them askey=valuepairs.WebhookHandlerhad the identical defect in the identical code path and isreached through the same
MultiplexHandler, so it is fixed too — fixingtwo of three would have left it live for anyone with
LOGGER_WEBHOOK_URLset.
WithAttrsaccumulates. It returns a new handler and never mutates thereceiver, so two loggers derived from one parent cannot leak attributes
into each other. That non-leakage is asserted, per handler.
WithGroupbehaves per theslog.Handlercontract rather than beingdocumented away: attributes attached after a
WithGroupare qualified byit — nested objects in json, dotted
group.key=valuein console. Itsdocumented edge cases are handled: empty
Attrignored, empty groupelided, empty-keyed group inlined,
WithGroup("")a no-op.the current implementation. The assertions read the bytes each handler
actually writes —
os.Stdoutthrough a pipe for console and json, theposted body via
httptestfor the webhook — not internal state.slog.Groupnesting and
slog.LogValuerresolution are covered as well.v1.0.2is not something I can do, so it is recorded inTODO.mdunder Future Steps rather than attempted.The root cause deserves naming: marshaling a
slog.Recordvalue cannot everwork, because a record keeps its attributes in unexported fields, so
encoding/jsononly ever sawTime,Message,LevelandPC. The fixbuilds the payload from
Record.Attrsinstead, resolving values throughslog.Value.Resolve— which also meansslog.Any("error", err)now reportsthe error message rather than the
{}thatencoding/jsonmakes of most errortypes. No dependency was added;
go.modandgo.sumare unchanged.Verification
Repo tooling only. Commit 1 checked out alone:
make testfails, 13 newfailures, e.g. the console handler handed
device,fileandattemptandprinting
... castingwith nothing after it. Branch head:make dockergreen,with
make fmt-check,make lintandmake testall genuinely executing inthe pinned container (no cached layers among them), and
make checkalso greenon the host. Working tree clean. Full pasted output is in the PR body.
Two ignored error returns are now checked explicitly, because current
golangci-lint no longer excludes them by default and
make checkfailed onthem outside the pinned container; that is the only change in the PR that is
not about attributes.
Left alone: the retag in #18 (no tag
created or pushed; the deadlock regression test still passes, since
JSONHandler.Handlestill writes straight toos.Stdoutand never re-entersthe stdlib
logpackage), and#17.