With slog's HandlerOptions.AddSource enabled, why does every record's source point at one helper file?
answer
- the record already carries a program counter
- the option resolves it, does not capture it
- frames are skipped by a fixed count
- your helper is the frame slog lands on
- build the record and pass the PC yourself
basics
~20 sAddSource resolves the program counter stored on the record, and slog's logging methods capture that counter at a fixed call depth. If every call goes through your own helper, the helper is what every record reports.
solid answer
~50 s`HandlerOptions.AddSource` tells the handler to add a `source` attribute with file, line and function, resolved from the program counter carried on the `slog.Record`. That counter is captured inside `Logger.Info`/`Logger.Log` by skipping a fixed number of frames, so it always names the immediate caller of the slog method. Wrap slog in your own `func logInfo(msg string, args ...any)` and that immediate caller is the wrapper — every record in the service then blames the same file and line, which makes AddSource worse than useless because it looks authoritative. The fix is to capture the PC yourself at the right depth with `runtime.Callers`, build the record with `slog.NewRecord(time.Now(), level, msg, pc)`, attach attributes with `Record.Add` or `Record.AddAttrs`, and call `logger.Handler().Handle(ctx, r)` directly — checking `Handler().Enabled(ctx, level)` first, since going straight to the handler skips the check the Logger would have made.
code
go · 10 linesfunc (l *Wrapper) Info(ctx context.Context, msg string, args ...any) {
if !l.h.Enabled(ctx, slog.LevelInfo) {
return
}
var pcs [1]uintptr
runtime.Callers(2, pcs[:]) // skip runtime.Callers and this method
r := slog.NewRecord(time.Now(), slog.LevelInfo, msg, pcs[0])
r.Add(args...)
_ = l.h.Handle(ctx, r)
}go deeper
Know that HandlerOptions.AddSource makes each record carry the file, line and function of the code that logged, and that it is a per-handler setting rather than something you pass per call.
Explain the two-stage mechanism: the Logger records a program counter with a fixed frame skip, and the handler resolves it only when AddSource is set. That split is what makes a wrapper function poison the result.
Diagnose it from the symptom — every record naming one file — and give the fix concretely: capture the PC with runtime.Callers at the wrapper's own depth, build the record with slog.NewRecord, and hand it to Handler().Handle after checking Enabled.
Own the policy call: AddSource is all-or-nothing per handler, so weigh the per-record resolution cost against unique-message discipline, and require that any logging wrapper the org ships is tested for the source it reports.
## What AddSource actually does `slog.HandlerOptions` has three fields, and `AddSource bool` is the one that makes a handler emit a `source` attribute — a `*slog.Source` carrying `Function`, `File` and `Line` — under the built-in key `source`. In JSON output that is a nested object; in text output it is rendered inline. The part worth internalising is *where the information comes from*. A `slog.Record` has a `PC` field: a `uintptr` program counter. The `Logger` methods capture it when the record is created, using `runtime.Callers` with a fixed skip count chosen so that the frame recorded is the code that called `Logger.Info`. `AddSource` does not capture anything — it only decides whether the handler spends the work of translating that PC into a file, line and function name at write time. That split matters twice: it explains the cost (the frame lookup is the expensive part, and it is paid in the handler, per record, only when the option is on), and it explains the bug. ## The bug: a wrapper eats the frame Teams wrap `slog` constantly, and for reasonable motives — to bind a request id, to enforce a house message format, to make the logger swappable in tests, or simply because the codebase already had `logInfo(msg, args...)` before `slog` existed and the migration kept the signature. ```go func logInfo(msg string, args ...any) { slog.Info(msg, args...) // this line is the caller slog records } ``` The skip count inside `slog` counts frames from `Logger.Info`. It has no way to know that the frame it lands on is a shim rather than real code. So the PC on every record points at that one line in that one file, and with `AddSource` on, every record in the service reports the same `source`. This is a nastier failure than having no source at all: an on-call engineer filters to an error, reads a precise `file:line`, opens it, and finds the logging helper. The information is not missing; it is confidently wrong. The same trap catches a wrapper one level up too — a `type Logger struct{ *slog.Logger }` with a method that calls the embedded logger's method — and it catches an ad-hoc `defer` or `errors`-handling helper that logs on the way out. ## Fixing it The standard fix is to stop using the `Logger` convenience methods inside the wrapper and construct the record yourself, so you control the skip count: ```go func (l *Wrapper) Info(ctx context.Context, msg string, args ...any) { if !l.h.Enabled(ctx, slog.LevelInfo) { return } var pcs [1]uintptr runtime.Callers(2, pcs[:]) // skip runtime.Callers and this method r := slog.NewRecord(time.Now(), slog.LevelInfo, msg, pcs[0]) r.Add(args...) _ = l.h.Handle(ctx, r) } ``` Four things are going on here: 1. **`runtime.Callers(skip, pc)`** fills `pc` with program counters. `skip = 0` is `runtime.Callers` itself, `1` is the function that called it — this method — and `2` is that method's caller, which is the code we actually want to blame. 2. **`slog.NewRecord(t, level, msg, pc)`** builds the record with that PC instead of one slog captures for us. 3. **`Record.Add(args...)`** takes the same alternating key/value form the `Logger` methods accept; `Record.AddAttrs` takes typed `slog.Attr` values instead. 4. **`Handler().Handle(ctx, r)`** bypasses the `Logger` entirely — which is the point, and also why the `Enabled` check has to be done explicitly first. Handing a record straight to a handler skips the check the `Logger` would have performed, so without that guard you do the record-building work even when nothing will consume it. The alternative fix is to have no wrapper: let call sites use `*slog.Logger` directly and get bound context via `Logger.With`, which returns a real logger rather than a shim. That removes the problem instead of compensating for it, and it is usually the better answer when the wrapper exists only to attach a couple of attributes. ## Is AddSource worth having on? It is a per-handler boolean, so it is on for every record or none. The value is highest when messages repeat across files (`"failed"`, `"retrying"`) and lowest when every message string is already unique enough to grep for. The cost is a frame resolution per emitted record plus three more fields on the wire. Measure it on your own hot path before deciding — and if you turn it on, verify on a real record that the file it names is a call site and not your logging package, because that check takes ten seconds and the failure mode above is silent. ## Interview framing Say where the PC comes from, that `AddSource` only resolves it, and that a fixed skip count plus a wrapper equals a permanently wrong answer. Then name the fix concretely: `runtime.Callers`, `slog.NewRecord`, `Handler().Handle`.
- Does turning HandlerOptions.AddSource off remove the cost of capturing the caller entirely?It removes the expensive half. The program counter is recorded on the record by the Logger methods regardless, which is cheap; what `AddSource` adds is resolving that counter into a function name, file and line inside the handler for every record it writes, plus the extra fields on the wire. That resolution is the part you are paying for.
- Why must a wrapper check Enabled explicitly when it calls Handler().Handle directly?Because the `Logger` is what normally performs that check, and going straight to the handler skips it. Without the guard the wrapper builds a record, allocates attributes and captures a frame for records the handler will immediately discard. The handler's own `Enabled(ctx, level)` answers the question cheaply before any of that work happens.
- How would you catch a wrong source attribute before it reaches production?Log one record through the wrapper in a test with a handler that captures the record, and assert that the resolved file is the test file rather than the logging package. It is a two-line check that pins the skip count, which is otherwise a magic number nobody notices when a refactor adds a frame.
It is like a return address stamped by the last person to touch the envelope. If everything in the building goes through one mail room, every letter comes back addressed to the mail room.
saying these in an interview costs you the question
- Thinks AddSource captures the stack rather than resolving a PC
- Believes the source attribute is computed at handler construction
- Adds a source attribute by hand instead of fixing the PC
- Assumes AddSource is free because the PC is already recorded
- Wraps slog in a helper and never checks what source reports