44291adcca
- Each module logs through diary.For(<package>): cabana, lagoon, attach, cooler, postcard, beachcomber, lighthouse, centrifugo, flare, phrasebook, wristband, bouncer - App-published *slog.Logger overrides stay first; messages and attributes unchanged - sunscreen: InstallDefault documented as the compatibility entry point; diary wraps every channel - READMEs list diary as a dependency; logging docs: plugins use diary.For
169 lines
10 KiB
Markdown
169 lines
10 KiB
Markdown
---
|
|
title: Logging
|
|
description: Configure log channels in config/log.yaml, log through diary component loggers and keep credentials out of log records.
|
|
section: services
|
|
order: 105
|
|
---
|
|
# Logging
|
|
|
|
SummerCMS logs through the standard library's `log/slog`, configured by [diary](../../modules/diary/README.md). Where a WinterCMS application lists channels in `config/logging.php` and calls `Log::error`, a SummerCMS application lists channels in `config/log.yaml` and logs through a component logger from `diary.For`. Every channel redacts credentials through [sunscreen](../../modules/sunscreen/README.md).
|
|
|
|
The application `main` that `summer build` generates calls `diary.Bootstrap(os.Stderr, diary.Options{})` as the first statement of `run`, so even configuration errors are logged, and `diary.Setup` right after `compass` has loaded `config/`. From then on component loggers, `slog.Default`, the package-level `slog` functions and the standard `log` package all write through the configured channels.
|
|
|
|
## Channels
|
|
|
|
A channel is a named destination with a driver:
|
|
|
|
| Driver | Writes |
|
|
|--------|--------|
|
|
| `console` | One line per record to stderr. With `format: auto` (the default) the line is styled when stderr is a terminal (time, level, the component as a fixed-width prefix, the message, `key=value` attributes) and logfmt otherwise, for systemd and Docker; `format: json` writes JSON lines. |
|
|
| `stderr` | logfmt (the default) or JSON to stderr, never styled. |
|
|
| `daily` | One file per day, JSON by default or logfmt; see [Daily files](#daily-files). |
|
|
| `stack` | Every record to each channel listed under `channels`. |
|
|
| `null` | Nothing. |
|
|
|
|
Each channel may set its own `level`; a record reaches a channel when it passes both its component's level and the channel's level.
|
|
|
|
## config/log.yaml
|
|
|
|
`summer new` writes this file, and an application without it gets the same values as framework defaults:
|
|
|
|
```yaml
|
|
# config/log.yaml
|
|
default: stack
|
|
level: info
|
|
channels:
|
|
stack:
|
|
driver: stack
|
|
channels: [console, daily]
|
|
console:
|
|
driver: console
|
|
format: auto
|
|
daily:
|
|
driver: daily
|
|
path: storage/logs/summer.log
|
|
days: 14
|
|
format: json
|
|
level: warn
|
|
components:
|
|
river: warn
|
|
http: info
|
|
```
|
|
|
|
`default` names the channel every record goes to, `level` is the global minimum, `channels` defines the channels and `components` sets levels per component (the `http: info` line only spells out what `level: info` already gives). It is the shape of Laravel's `config/logging.php` (`default`, `channels` with a `driver` each, `stack` and `daily` drivers, `days` for retention), written in YAML. The framework defaults also define a `stderr` channel (logfmt) and a `null` channel, so `default: stderr` or `default: null` works without defining them.
|
|
|
|
Like any key, these can be overridden from the environment with a double underscore between path segments, and string values are accepted where YAML would give a number or a list:
|
|
|
|
```sh
|
|
SUMMER_LOG__CHANNELS__DAILY__DAYS=30
|
|
SUMMER_LOG__CHANNELS__STACK__CHANNELS=console,daily
|
|
SUMMER_LOG__COMPONENTS__RIVER=error
|
|
```
|
|
|
|
An override changes one key and keeps every other default. An unknown driver, format or level, a stack that names a missing channel or contains itself, and a daily path outside the application root stop the start-up with an error that names the key, for example `diary: log.channels.daily.days must be a whole number of at least 0`.
|
|
|
|
## Component loggers
|
|
|
|
Code logs through the logger of its component:
|
|
|
|
```go src=modules/diary/example_test.go#ExampleFor
|
|
// Before diary.Setup runs, records go to the process default logger.
|
|
// This one drops the time so the output is stable.
|
|
previous := slog.Default()
|
|
defer slog.SetDefault(previous)
|
|
slog.SetDefault(slog.New(slog.NewTextHandler(os.Stdout, &slog.HandlerOptions{
|
|
ReplaceAttr: func(groups []string, a slog.Attr) slog.Attr {
|
|
if len(groups) == 0 && a.Key == slog.TimeKey {
|
|
return slog.Attr{}
|
|
}
|
|
return a
|
|
},
|
|
})))
|
|
|
|
// After diary.Setup the same record reaches the configured channels and
|
|
// passes log.components.blog, else log.level.
|
|
blogLog.InfoContext(context.Background(), "post published", "id", 7)
|
|
// Output:
|
|
// level=INFO msg="post published" component=blog id=7
|
|
```
|
|
|
|
Every record carries the attribute `component=blog`, and passes the component's level: `log.components.blog` when it is set, `log.level` otherwise. The name is the plugin or module code without dots, because configuration keys split on dots (`acme.blog` would nest). Framework modules use their package name (`cabana`, `lagoon`, `conga`), River logs as `river` and GORM as `db`. `diary.SetVerbosity` lowers every component to info (1) or debug (2 and more) at runtime.
|
|
|
|
`diary.For` is safe in a package `var` block: before `diary.Setup` runs, its records go to the process default logger, and after it they reach the configured channels. Records logged through `slog.Default` carry no component and use `log.level`.
|
|
|
|
## Daily files
|
|
|
|
A daily channel with `path: storage/logs/summer.log` writes `storage/logs/summer-2026-10-21.log` today and `storage/logs/summer-2026-10-22.log` after local midnight. A relative path resolves against the application root, the directory that holds `config/`, and may not leave it; an absolute path is used as given. Files are created with mode 0640 in directories created with mode 0750, because logs carry user identifiers, and a file is only created once a record reaches it. With `days: 14` the files of today and the 13 days before are kept and older files of the same name pattern are deleted; other files in the directory are never touched. `days: 0` keeps every file.
|
|
|
|
If the directory cannot be created or the file cannot be opened (a read-only container filesystem, missing permissions), the channel logs one warning from component `diary` on the console naming the path and the error, and is disabled. The start-up never fails because of a log file.
|
|
|
|
## Redaction
|
|
|
|
Every channel, console, stderr, daily and null alike, is wrapped by `sunscreen.Wrap`, which rewrites every record before it is written:
|
|
|
|
- The value of an attribute whose key is one of `sunscreen.RedactedKeys` becomes `[REDACTED]`, at any group depth and whatever the letter case: `api_key`, `apikey`, `authorization`, `bearer`, `password`, `secret`, `token`, `webhook_secret`, `admin_password` and the `openai_api_key`, `anthropic_api_key` and `perplexity_api_key` variants.
|
|
- The message, string values, error values and the formatted text of other values are passed through `sunscreen.Scrub`, which replaces `Bearer <token>`, `sk-` style API keys and `x-api-key: <value>`.
|
|
- `slog.LogValuer` values are resolved first, and maps such as `http.Header` are redacted key by key.
|
|
|
|
```go src=modules/sunscreen/example_test.go#ExampleWrap
|
|
// Drop the time so the output is stable; a real application keeps it.
|
|
plain := slog.NewTextHandler(os.Stdout, &slog.HandlerOptions{
|
|
ReplaceAttr: func(groups []string, a slog.Attr) slog.Attr {
|
|
if len(groups) == 0 && a.Key == slog.TimeKey {
|
|
return slog.Attr{}
|
|
}
|
|
return a
|
|
},
|
|
})
|
|
logger := slog.New(sunscreen.Wrap(plain))
|
|
|
|
logger.Info("vendor call failed",
|
|
"api_key", "live-key-123",
|
|
slog.Group("request", slog.String("Authorization", "Bearer abc.def")),
|
|
"err", errors.New("401 for key sk-abcdefghijklmnopqrstuvwx"),
|
|
)
|
|
// Output:
|
|
// level=INFO msg="vendor call failed" api_key=[REDACTED] request.Authorization=[REDACTED] err="401 for key sk-[REDACTED]"
|
|
```
|
|
|
|
`sunscreen.InstallDefault` remains for programs that install their own default logger instead of diary.
|
|
|
|
## Logging from a plugin
|
|
|
|
A plugin logs through its own component logger, named after its plugin code without dots, instead of the process default logger. The logger is safe to create in a package `var` block, before diary is set up:
|
|
|
|
```go src=modules/diary/example_test.go#blogLog
|
|
// blogLog is the component logger of a blog plugin, created once in a
|
|
// package var block, before diary is set up.
|
|
var blogLog = diary.For("blog")
|
|
```
|
|
|
|
Its records carry `component=blog`, follow `log.components.blog` and go through the redacting channels.
|
|
|
|
Redaction is a safety net for mistakes, not a way to log secrets on purpose. Log identifiers and outcomes: the record id, the vendor, the status code, how long it took. Never log request arguments, tokens, credentials or request and response bodies, which can carry personal data the patterns do not recognise.
|
|
|
|
## Request log
|
|
|
|
The router can log every request. It is off by default; turn it on with the `http.access_log` key (environment `SUMMER_HTTP__ACCESS_LOG=true`):
|
|
|
|
```yaml
|
|
# config/http.yaml
|
|
access_log: true
|
|
```
|
|
|
|
Each request then writes one Info record with the message `http request` once it has been served:
|
|
|
|
| Attribute | Value |
|
|
|-----------|-------|
|
|
| `method` | The request method. |
|
|
| `pattern` | The matched route, method and path pattern, for example `GET /posts/{id}`. Empty when no route matched. |
|
|
| `status` | The response status; a handler that writes without setting one counts as 200. A 5xx is logged as 499 (client closed request) only when the client had already gone away when the status was written and the handler did not panic: the error came from the cancellation, and no client received it. A 5xx written before the client went away keeps its status, and a recovered panic is always 500, so a search for 5xx records finds every real server error. |
|
|
| `duration_ms` | Time spent serving the request, in whole milliseconds. |
|
|
| `client_gone` | `true` when the client went away before the request was served (its context ended with `context.Canceled`); absent otherwise. |
|
|
|
|
The record never carries the URL path, the query string, request or response headers or the client address, because tokens often travel in paths and query strings. That holds for a request that reached no route too: a token route requested with another method gets a 405 from the router, and its trailing-slash variant a 404, before any route handler runs, so the path would carry the token. It goes to the published `*slog.Logger` or `slog.Default`, so the redacting handler still applies. Grep for the empty `pattern` to find requests that reached no route; the client's own log (a browser, a proxy) shows which path it asked for.
|
|
|
|
## Panics
|
|
|
|
The router recovers a panicking handler and answers with an opaque 500: the JSON groups send `{"error":true,"message":"Internal server error"}` and the raw groups an empty body. The panic value never reaches the client. See [Routing](routing.md).
|