Anti-patterns

Every example below shipped and passed review in a GFiber service. Check for these first when auditing.

Printing a pointer instead of the data

logging.LogInfoCtx(ctx, "Valid alarms: %+v", validAlarms)   // map[string]*Alarm
logging.LogInfoCtx(ctx, "Alarm results: %+v", alarmResults) // map[string]*AlarmResult

Go's fmt does not dereference pointers held inside a map or a slice, so what reaches Graylog is a map key and a heap address:

Valid alarms: map[7c0e-1:0x7cabe66aa060]
Alarm results: map[7c0e-1:0x7cabe66b4000]

Print the identifiers, or a count. A struct or map of values prints fine; a map or slice of pointers does not.

A verb that is not a verb

logging.LogDebug("... for alarm %s+", alarm) // *Alarm

%s+ is %s followed by a literal plus. On a struct with non-string fields %s emits error markers:

&{7c0e-1 %!s(int=3) %!s(bool=false) 2026-09-02 11:52:06 ...}+

Use %+v, or a short projection method such as toShortString().

INFO inside a per-object loop

for _, target := range targets {
    ...
    logging.LogInfo("ONT target %s is not eligible for this ticket: %+v", ontId, target)
}

One INFO line per monitoring target, dumping the whole struct, where the logged branch is the normal outcome and not an exception. This scales with ONT count, not with request count. Log the members at DEBUG and one count after the loop.

A tick that logs whether or not there is work

logging.LogInfoCtx(ctx, "Schedule ticket updates at %v", time.Now())

Fired on every scheduler tick. With a five second interval that is roughly 17k INFO lines per day per pod with no work behind them. The tick belongs at DEBUG; the INFO line belongs after the batch, with counts.

A rejection that returns in silence

A request rejected for capacity, for an unmatched handler or for a malformed body, returning a status code with no log line and no metric. Every identifier in that request is then absent from Graylog, and the request counter and the result counter diverge with nothing to explain the gap.

A result line that never runs

An early return on a failure path that skips the per-item result loop. The batch is lost and leaves one line with no identifier in it. Populate the results on every exit path, or carry the identifiers on the ERROR.

Watch the status code when fixing this: in gfiber-policy-executor filling the results made a fully failed batch fall through the handler condition and answer HTTP 200, and the caller only inspects the status code, so it would have marked the work completed.

Losing the panic value

logging.LogErrorCtx(ctx, "Unexpected panic: %v", reasonConstant, stackTrace)

One verb, two arguments. The recovered value is never printed and the stack trace arrives as %!(EXTRA string=...).

A line whose whole content is already in the prefix

logging.LogInfoCtx(ctx, "x-request-id=%s", requestId)

The runtime prefix already carries request_id. The line names no work item, so it costs volume and answers nothing. Replace it with a work-received line that names the ticket or alarm.

Retry semantics inverted

Logging every retry attempt at WARN while the exhaustion, the moment the work actually moves to a backlog, is silent. The attempt is DEBUG, the exhaustion is ERROR with the identifier.

Non-context logging

logging.LogInfo and friends without Ctx drop request_id and every business identifier from the MDC, which makes the line impossible to attach to anything.

If the enclosing function has no ctx and it is a pure helper, do not thread ctx through several signatures only to log. Either move the line to the caller, which has the context, or drop it: a DEBUG line that cannot be correlated is close to useless when two work items are in flight.

3.8 KiB Raw Permalink Blame History