skip to content

Why can WithAttrs in a custom slog.Handler let two derived loggers overwrite each other's attributes?

level: seniorimportance: should knowfreq 27%

answer

  1. copying the struct copies a header, not elements
  2. append reuses room when there is room
  3. two children, one parent, one array slot
  4. single goroutine, so -race says nothing
  5. cap the parent to its length before appending

basics

~10 s

append reuses spare capacity, so a WithAttrs that does append(h.attrs, new...) lets two children write into the same backing array slot; the second overwrites the first. Clip or copy the parent's slice first.

solid answer

~40 s

The usual `WithAttrs` implementation shallow-copies the handler and appends: `h2 := *h; h2.attrs = append(h.attrs, as...)`. Copying the struct copies the slice *header*, not the elements, so the child still points at the parent's backing array. When the parent's slice has spare capacity — and after one round of `append` it usually does — a second child appends into the very same array slot the first child is using, and now the two derived loggers read each other's attributes. It is not a data race: two sequential `logger.With(...)` calls on one goroutine reproduce it, so `-race` stays silent and the contract suite does not catch it either. The fix is to make `append` allocate: `append(slices.Clip(h.attrs), as...)`, or the three-index form `h.attrs[:n:n]`, or allocate exactly `len(h.attrs)+len(as)` and copy. Cap the parent, never trust its capacity.

code

go · 5 lines
go
func (h *handler) WithAttrs(as []slog.Attr) slog.Handler {
	h2 := *h
	h2.attrs = append(h.attrs, as...) // may write into the parent's array
	return &h2
}

go deeper

for a junior

Know that a slice variable is a view over an array and that copying it copies the view. Two views can point at the same memory.

for a middle

Explain when append reuses spare capacity versus allocating, and show the three-index or slices.Clip fix that forces a fresh array.

for a senior

Diagnose it without a race report: reason from the symptom of sibling loggers sharing attributes to slice aliasing, and add the two-sibling regression test to the handler's suite.

for a principal

Set the rule for a shared handler module: derivation copies, records are cloned before retention, and the contract suite is supplemented by a sibling-independence test before anything is tagged.

## The bug as it shows up An internal logging handler is published as a module several teams import. Each service builds one base logger with common fields, then derives per-subsystem loggers from it: ```go base := slog.New(New(os.Stdout)).With("service", name) ordersLog := base.With("subsystem", "orders") billingLog := base.With("subsystem", "billing") ``` Lines from `ordersLog` start arriving tagged `subsystem=billing`. Nothing is concurrent — the two derivations happen back to back during start-up. ## The mechanism A slice value is a three-word header: pointer to a backing array, length, capacity. Copying a struct that contains a slice copies the header; both copies then reference the same array. `append(s, x)` writes into `s`'s spare capacity when `cap(s) > len(s)`, returning a header with the same array pointer and a longer length. It allocates a *new* array only when there is no room. So: 1. `base` holds `attrs` with `len == 1` and, because a previous `append` grew it, `cap == 2`. 2. `ordersLog`'s `WithAttrs` does `append(base.attrs, subsystemOrders)`. There is room, so it writes `orders` into index 1 of the shared array and returns a header of length 2 over that same array. 3. `billingLog`'s `WithAttrs` starts from `base.attrs` again — still length 1, capacity 2 — and writes `billing` into index 1 of the *same* array. 4. Both children have length-2 headers over one array whose index 1 now reads `billing`. The parent is untouched, which is why the handler passes a test that only checks the base logger. The corruption is between siblings. ## Why the usual tools miss it - **The race detector.** There is no race: the writes happen on one goroutine, in order. `go test -race` is silent. Reaching for it first is the diagnostic mistake here, and it costs a lot of time. - **The contract suite.** `slogtest` composes derivation in a single chain — `WithAttrs` then `WithGroup` then `WithAttrs` — so it never creates two siblings from one parent. It will not report this. - **Review.** `h2 := *h` followed by `append(h.attrs, ...)` reads as obviously correct to anyone who has not been bitten. It looks like a copy. The test that does catch it is small and belongs in every handler's suite: derive two loggers from one parent, log through both, assert each line carries only its own attributes. ## The fix Make `append` unable to reuse the parent's array by capping the parent's slice to its length: ```go h2.attrs = append(slices.Clip(h.attrs), as...) ``` `slices.Clip` returns `s[:len(s):len(s)]` — same elements, capacity equal to length — so the very next `append` must allocate. The three-index slice expression written by hand is identical, and equally fine. The explicit alternative allocates exactly what is needed and copies: ```go attrs := make([]slog.Attr, 0, len(h.attrs)+len(as)) attrs = append(attrs, h.attrs...) attrs = append(attrs, as...) ``` That form costs a copy of the parent's attributes per derivation, which is the price of correctness; loggers are derived far less often than records are written, so it is the right place to spend. A note on ownership: the interface documentation says the handler takes ownership of the `attrs` slice it is *given*, so you may retain or modify that argument. That is the opposite of the receiver's own slice, which the parent still owns and you must not extend into. Reading the ownership rule as permission to append into the parent is exactly how the bug is introduced. ## The same shape elsewhere in slog `slog.Record` has the same hazard. Copies of a `Record` share state — its attributes live partly in a slice — so a handler that keeps a record beyond `Handle`, or that adds attributes to it before passing it on to a wrapped handler, must call `r.Clone()` first. `Clone` returns a copy that shares no state. A wrapping handler that does `r.AddAttrs(extra); return inner.Handle(ctx, r)` without cloning can scribble into storage the caller still holds, and produces the same class of impossible-looking output. The general rule for handler authors: any slice reachable from a value you did not create is shared until you prove otherwise. Cap it, clone it, or copy it.

  • Write the test that would have caught this before the module was tagged.
    Derive two loggers from one base with different attributes, log one record through each into a shared buffer, and assert each line carries only its own attribute. Derive from a base that has already been derived once, so the parent's slice has spare capacity — a base built fresh may have capacity equal to length and hide the bug entirely.
  • The Handler docs say WithAttrs owns the slice it is given. Does that permit appending into the receiver's slice?
    No. Ownership covers the `attrs` argument the caller passed in, which you may retain or modify. The receiver's own slice belongs to the parent handler, which is still live and still logging. Appending into its spare capacity mutates memory another handler is using, which is precisely the bug.
  • Where does the same aliasing hazard appear with slog.Record?
    Copies of a Record share state, so a wrapping handler that calls AddAttrs on the record it received, or that keeps the record past the return of Handle, can corrupt storage the caller still holds. Record.Clone returns a copy sharing no state; call it before you retain or modify.
  • Would a heap profile or the race detector help you find this?
    Neither. There is no race — two sequential derivations on one goroutine reproduce it — and no leak, so a heap profile shows nothing unusual. The only reliable diagnostic is a test that creates sibling loggers, plus reading WithAttrs with slice aliasing in mind.

Two people are handed the same notepad opened at page one and each writes on the next blank line. Both believe the page is theirs; only the second one's words survive.

saying these in an interview costs you the question

  • Reaches for the race detector first and stops when it is silent
  • Thinks append always returns a fresh array
  • Believes copying the handler struct deep-copies its slices
  • Says slogtest would have caught it
  • Reads slice ownership of the argument as licence to extend the parent