Logging

In production your logs are how you find out what went wrong. Vukem logs with the standard library's log/slog: one structured line per request, one per failed scheduled task, and the security events of the framework. This page lists those fields and the settings that shape them.

You will learn:

• which fields every request line has, and at which level it is logged;
• how the default logger is built, and how repeated errors become one summary;
• what changes when you pass your own logger with WithLogger;
• what scheduled tasks log, and how to count their runs.

The idea#

A log line is a set of key/value pairs, not a sentence. slog writes them as key=value text in development and as one JSON object per line to standard error in production. On Railway that JSON is the log path: the platform collects stdout and stderr, and Log Explorer indexes the objects. Nothing in the framework ships those lines to another log vendor. Health checks for load balancers are covered in Single binary.

The request line#

DefaultMiddleware logs every request after the response with the message request:

The level follows the status: ERROR for 5xx, WARN for 4xx, INFO otherwise.

Every field above is always present except route. Fields added with web.AddLogAttrs follow them.

Secrets in the path#

A path can carry a secret: the token of /reset-password/{token}, the key of a signed download. The query string is never logged, but the path is. Mark those parameters on the route, and every log line of the request writes {name} instead of the value: the request line, the error log of a failed handler and security-event logs (and the Path of security.Event).

r.Get("/reset-password/{token}", passwords.ShowReset).SecretParams("token")

{"msg":"request","method":"GET","path":"/reset-password/{token}","status":200,
 "route":"GET /reset-password/{token}"}

A whole path segment equal to the value is replaced; a {name...} wildcard value is replaced wherever it appears. Your own logs can do the same with web.LogPath(r) instead of r.URL.Path.

Adding fields to the request line#

web.AddLogAttrs(ctx, attrs...) adds attributes to the request line of the current request, so it stays one line per request with everything your dashboards need. Call it from any middleware or handler under the logger, before or after the handler runs: the line is written once the response is done. A middleware that runs after authentication can add a hashed user id:

func LogUser(next http.Handler) http.Handler {
	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		if u, err := auth.UserFrom[*User](r.Context(), "web"); err == nil {
			web.AddLogAttrs(r.Context(), slog.String("user", hashID(u.ID)))
		}
		next.ServeHTTP(w, r)
	})
}

Without the request logger in the chain, AddLogAttrs does nothing. Never add secrets, tokens or raw personal data: the request line goes wherever your logs go.

With OpenTelemetry installed, the request line also carries trace_id and span_id, so you can jump from a log line to its trace.

In a handler, c.Log() returns the app's logger. Values of type config.Secret print as [redacted], so a configuration struct may be logged whole.

The default logger#

Unless you pass your own, the app builds its logger from configuration:

It writes to standard error (WithLogOutput(w) changes that). When Telegram logging is configured, the same records also go to the chat.

Repeated errors become one summary#

When a database goes down, every request fails with the same error. Thousands of identical lines hide everything else and, with Telegram on, flood the chat. The dedup handler (logging.NewDedup) writes the first ERROR record of a kind and counts the repeats inside the window. Two records are the same kind when they share level, message, the logger's attributes and the values of event, error and err. When the window ends, one record with the message repeated carries:

Only ERROR records are collapsed. More than 1024 different kinds in one window pass through unchanged, so a burst of distinct errors is never hidden. app.Shutdown flushes pending summaries, so a deploy does not lose them. The dedup handler sits in front of Telegram too: an error burst is one chat message plus a summary.

logging.NewDedup(next, logging.DedupOptions{Window: time.Minute}) is a normal slog.Handler; you may use it in front of any handler of your own.

Passing your own logger#

vukem.WithLogger(l) uses l as given:

• LOG_LEVEL, LOG_FORMAT and WithLogOutput are ignored: your handler decides level, format and output.
• LOG_DEDUP_WINDOW is ignored: wrap your handler with logging.NewDedup yourself if you want summaries.
• Telegram logging, when configured, is still added next to your handler.

Scheduled tasks#

The scheduler logs to schedule.Options.Log (the app logger under app.Schedule), with a task field naming the task:

There is no metrics hook on the scheduler. To count runs or time them, wrap the task function:

func timed(name string, fn func(context.Context) error) func(context.Context) error {
	return func(ctx context.Context) error {
		start := time.Now()
		err := fn(ctx)
		taskRuns.Record(ctx, time.Since(start), name, err) // your metric

		return err
	}
}

s.Func("prune-sessions", timed("prune-sessions", pruneSessions)).Hourly()

Security#

• Request lines never contain query strings, headers, cookies or bodies.
• config.Secret values are redacted wherever they are logged.
• Security events (failed logins, rejected tokens, blocked addresses) are WARN records with an event field; see Building blocks.

Next steps#

• OpenTelemetry: traces and log correlation.
• Telegram logging: errors in a chat.
• Releases and stability: what an upgrade may change.