skip to content

When should you guard runtime/trace.Logf with trace.IsEnabled, and what does the guard actually save?

level: middleimportance: nice to knowfreq 20%

answer

  1. the call is cheap; the arguments are not
  2. it already checks before formatting
  3. boxing into a variadic slice still happens
  4. the answer may be stale immediately
  5. never let behaviour depend on it

basics

~20 s

Guard when building the arguments costs something. trace.Logf already skips its own formatting while tracing is off, but the caller still evaluates and boxes the arguments; trace.IsEnabled skips that work. Treat the answer as advisory only.

solid answer

~50 s

`trace.Log(ctx, category, message)` and `trace.Logf(ctx, category, format, args...)` attach an instant event to whatever task the context carries, which is how a document id or a batch size gets onto an otherwise anonymous interval in `go tool trace`. `Logf` itself checks whether tracing is on before doing the `fmt.Sprintf`, so the guard is not about the formatting. What the guard saves is everything the *caller* does to produce the arguments: the variadic slice and the boxing of each value into it, plus any real work you do at the call site — a checksum, a `len` over something you had to build, a `String()` on a large struct. So wrap those calls in `if trace.IsEnabled()`, and leave a plain `trace.Log(ctx, "stage", "start")` unguarded. And treat `IsEnabled` as advisory: tracing can start or stop immediately after it returns, so the value is already potentially stale — never let program behaviour depend on it.

code

go · 10 lines
go
func normalize(ctx context.Context, doc Document) {
	defer trace.StartRegion(ctx, "normalize").End()

	if trace.IsEnabled() {
		trace.Logf(ctx, "doc", "id=%s bytes=%d sum=%x",
			doc.ID, len(doc.Body), checksum(doc.Body))
	}

	strip(doc)
}

go deeper

for a junior

Know that trace.Log and trace.Logf attach a short message to the operation currently being traced, and that the message is where identifiers such as a document id belong.

for a middle

Be able to say what still costs the caller when tracing is off: the arguments are evaluated and boxed at the call site even though Logf skips its own formatting. That is what the IsEnabled guard removes.

for a senior

Demonstrate judgement about annotation budget on hot paths — measure with a benchmark including allocations, guard only the calls whose arguments cost real work, and never let the guard change behaviour.

for a principal

Set the policy for what shared code is allowed to annotate and at what call rate, so that instrumentation added by one team does not become a measurable tax on every caller of a common library.

## What the log annotations do Tasks and regions give a trace intervals. `trace.Log` and `trace.Logf` give it **instants**: a one-off event, carrying a category and a message, attached to the task held in the context. In `go tool trace`, those events appear in the task's event list interleaved with its region starts and ends, so a task that would otherwise be an anonymous 400 ms bar becomes "document 8812, 4.2 MB, retry 1, parse started, parse ended". The two functions are: - `trace.Log(ctx context.Context, category, message string)` - `trace.Logf(ctx context.Context, category, format string, args ...any)` The **category** is a grouping label and the documentation is explicit that the API expects only a small number of distinct categories in a program — the same low-cardinality discipline that applies to task and region types. The **message** is where per-instance detail goes. ## Where the cost actually is The interesting engineering question is what an annotation costs when nobody is tracing, because that decides whether you can leave the calls in production code permanently. Inside `Logf`, the formatting is already conditional: it checks whether tracing is enabled before calling `fmt.Sprintf`. So the common belief — "I need `IsEnabled` or I pay for the Sprintf on every call" — is wrong about the formatting. What is *not* conditional is everything that happens before control reaches `Logf`: 1. **Argument evaluation.** Go evaluates arguments at the call site. `trace.Logf(ctx, "doc", "sum=%x", checksum(body))` runs `checksum(body)` whether or not anyone is tracing. 2. **Variadic boxing.** `args ...any` means each argument is converted to an interface value and packed into a slice at the call site. That is per-call work, and depending on escape analysis it can allocate. 3. **Anything you wrote for the trace's benefit.** Building a summary string, walking a map to count entries, serialising a struct. `trace.IsEnabled()` guards all three: ```go if trace.IsEnabled() { trace.Logf(ctx, "doc", "id=%s sum=%x", doc.ID, checksum(doc.Body)) } ``` On a path that runs a few hundred times a second, none of this matters and the guard is noise. On a path that runs millions of times a second, or where the arguments are expensive, the guard is the difference between annotation you can ship and annotation you cannot. The honest way to decide is a benchmark with allocation counts, not intuition. ## Why IsEnabled is advisory The documentation says the result is advisory only: tracing may have started or stopped by the time the function returns. Tracing is turned on and off by other goroutines, and there is no lock you hold across the check and the call. The practical consequences are mild for annotation: - If it returns false and tracing starts a microsecond later, you skip one log event. You lose a little detail at the very start of a recording. - If it returns true and tracing stops, the `Logf` becomes a no-op. Nothing breaks. The consequences are severe if you use it for anything else. `IsEnabled` must never gate a code path, a return value, a lock, an error, or a retry. A program whose behaviour differs depending on whether someone is recording a trace is a program whose bug disappears exactly when you go looking for it — and because the flag can flip mid-function, two checks in the same function can disagree. ## How this fits the rest of the annotation API A reasonable division of labour for a staged pipeline: - **Task type** — the kind of operation: `"ingest"`. Fixed vocabulary. - **Region type** — the stage: `"parse"`, `"normalize"`, `"index"`. Fixed vocabulary. - **Log category** — the kind of fact: `"doc"`, `"retry"`. Small fixed set. - **Log message** — the varying detail: ids, sizes, counts. Unbounded cardinality lives here and only here. That split exists because the aggregate views group by the type and category strings and show per-group latency; the message is free text the tool shows but does not group on. Push cardinality down into the message and the views stay useful. ## The habit to take away Leave unguarded logs whose arguments are already sitting in a variable. Guard the ones that make you compute something. Never guard on `IsEnabled` for any reason other than skipping annotation work, and remember that the value is a hint about the past, not a promise about the next instruction.

  • What does a trace.Log event look like in the user-task view, and what belongs in the message?
    It shows as an instant event on the task, carrying its category and message, ordered among that task's region starts and ends. Put the per-instance facts there — document id, byte count, retry number — and keep the category, like the task and region type strings, a small fixed vocabulary, because the views group on those and a unique category per item destroys the grouping.
  • Why is trace.IsEnabled a bad basis for a program decision?
    Because it is advisory: another goroutine can start or stop tracing immediately after it returns, so the value is stale as soon as you have it, and two checks in one function can disagree. Use it only to skip work that exists solely to produce annotations. Anything correctness-bearing must behave identically whether or not a trace is being recorded.
  • How would you decide whether an annotation is too expensive to leave in?
    Benchmark the function with and without the annotation and compare both time and allocations per operation. The suspicious cases are hot inner loops and arguments that force work or escape to the heap. If the delta matters, either guard the call with IsEnabled or move the annotation out to a coarser boundary where it runs orders of magnitude less often.

saying these in an interview costs you the question

  • Thinks Logf formats the message even when tracing is off
  • Uses IsEnabled to choose a code path
  • Emits a distinct log category per document
  • Assumes annotations are free at any call rate
  • Treats IsEnabled as a stable, synchronised flag