docs(19.8-01): complete diary logging plan
This commit is contained in:
Jakub Zych
@@ -0,0 +1,261 @@
|
||||
---
|
||||
phase: 19.8-console-commands-overhaul
|
||||
plan: 01
|
||||
subsystem: logging
|
||||
tags: [slog, diary, lipgloss, colorprofile, logging, gorm, river, sunscreen]
|
||||
|
||||
requires:
|
||||
- phase: 08
|
||||
provides: sunscreen redaction handler (sunscreen.Wrap)
|
||||
provides:
|
||||
- "modules/diary: For, Bootstrap, Setup, SetVerbosity, Verbosity, Reset, Close, ParseConfig, DefaultConfig, NewConsoleHandler"
|
||||
- "Laravel-shaped config/log.yaml (log.default, log.level, log.channels, log.components) with console, stderr, daily, stack and null drivers"
|
||||
- "bonfire palette and color detection: ColorMode, Palette, DefaultPalette, DetectProfile"
|
||||
- "Generated main runs diary.Bootstrap first and diary.Setup after compass.Load; summer new writes config/log.yaml"
|
||||
- "River (river), GORM (db) and every framework module log through diary component loggers"
|
||||
affects: [19.8-02, 19.8-03, 19.8-04, console, logging, surf request log]
|
||||
|
||||
actuals:
|
||||
tokens: 53887
|
||||
tasks: 3
|
||||
commits: 6
|
||||
plan_head_before: bde7d9fcb7a2a8dcb0ba9eaa7bcbfd2e22975679
|
||||
plan_head_after: 44291adccaf711cf1a32fd7fdb203a7a375081b9
|
||||
|
||||
tech-stack:
|
||||
added:
|
||||
- "charm.land/lipgloss/v2 v2.0.6"
|
||||
- "github.com/charmbracelet/colorprofile v0.4.3"
|
||||
patterns:
|
||||
- "Proxy component handler: diary.For returns a logger whose handler looks up the live channel tree at log time, so package-level loggers created before setup route correctly"
|
||||
- "Every channel leaf wrapped by sunscreen.Wrap and gated by its own slog.LevelVar; stacks via slog.NewMultiHandler"
|
||||
- "Per-package unexported moduleLog = diary.For(<package>); app-published *slog.Logger still wins where a module already preferred it"
|
||||
|
||||
key-files:
|
||||
created:
|
||||
- .planning/notes/2026-10-21-console-charm-stack.md
|
||||
- modules/bonfire/styles.go
|
||||
- modules/diary/diary.go
|
||||
- modules/diary/config.go
|
||||
- modules/diary/component.go
|
||||
- modules/diary/console.go
|
||||
- modules/diary/daily.go
|
||||
- modules/diary/channels.go
|
||||
- modules/diary/README.md
|
||||
- modules/diary/tracer_smoke_test.go
|
||||
- modules/diary/config_smoke_test.go
|
||||
- modules/diary/example_test.go
|
||||
- modules/cabana/log.go
|
||||
- modules/conga/logger_smoke_test.go
|
||||
- modules/lagoon/logger_smoke_test.go
|
||||
- internal/build/testdata/new/config__log.yaml.golden
|
||||
modified:
|
||||
- internal/build/build.go
|
||||
- internal/build/new.go
|
||||
- internal/build/stubs/new.tmpl
|
||||
- examples/hello/main.go
|
||||
- modules/conga/client.go
|
||||
- modules/lagoon/connection.go
|
||||
- modules/sunscreen/sunscreen.go
|
||||
- docs/services/logging.md
|
||||
- docs/setup/configuration.md
|
||||
- docs/services/configuration.md
|
||||
- README.md
|
||||
- go.mod
|
||||
|
||||
key-decisions:
|
||||
- "Charm v2 stack on charm.land paths recorded before any charm import; this plan installs only lipgloss v2.0.6 and colorprofile v0.4.3, plan 2 installs bubbletea v2.1.0, bubbles v2.2.1, huh v2.0.3 and fang v2.0.1 (newest tags on 2026-10-21, equal to the research pins)"
|
||||
- "diary's console handler is its own lipgloss handler; charm's slog logger rejected (fails testing/slogtest); daily files use a stdlib writer, lumberjack rejected"
|
||||
- "format auto picks the styled console handler when bonfire.DetectProfile reports more than NoTTY, so --no-ansi (ColorNever) gives logfmt lines, not unstyled console lines"
|
||||
- "Daily retention keeps the files of today and the days-1 days before (Laravel's maxFiles count), not days+1 files"
|
||||
- "Framework defaults also define stderr (logfmt) and null channels so log.default can name them without defining them"
|
||||
- "wristband and bouncer now import diary (plan: every framework module); their READMEs no longer call them dependency-free leaves. This amends the leaf consequence of .planning/notes/2026-10-19-oidc-on-wristband-golang-jwt.md and needs the user's confirmation"
|
||||
|
||||
patterns-established:
|
||||
- "Component names are plugin or module codes without dots; framework modules use their package name"
|
||||
- "Tests that set diary up call t.Cleanup(diary.Reset), which restores slog.Default and the log package's output"
|
||||
|
||||
requirements-completed: [SC-1, SC-2, D-01, D-02, D-04, D-05, D-08, D-09, D-10, D-12]
|
||||
|
||||
coverage:
|
||||
- id: D1
|
||||
description: "Charm v2 decision note committed before go.mod requires lipgloss, with STACK.md rows"
|
||||
requirement: D-02
|
||||
verification:
|
||||
- kind: other
|
||||
ref: "git merge-base --is-ancestor e6039b4 e903cc3 (acceptance criterion 1 of Task 1)"
|
||||
status: pass
|
||||
human_judgment: false
|
||||
- id: D2
|
||||
description: "A component logger record flows from config/log.yaml through compass into a redacting console and daily stack"
|
||||
requirement: SC-1
|
||||
verification:
|
||||
- kind: unit
|
||||
ref: "modules/diary/tracer_smoke_test.go#TestDiaryTracerSmoke"
|
||||
status: pass
|
||||
human_judgment: false
|
||||
- id: D3
|
||||
description: "SUMMER_LOG__ overrides parse as strings and overlay defaults; invalid values fail naming the key"
|
||||
requirement: D-08
|
||||
verification:
|
||||
- kind: unit
|
||||
ref: "modules/diary/config_smoke_test.go#TestConfigEnvSmoke"
|
||||
status: pass
|
||||
human_judgment: false
|
||||
- id: D4
|
||||
description: "Unwritable daily directory warns once on the console and never fails Setup"
|
||||
requirement: D-10
|
||||
verification:
|
||||
- kind: unit
|
||||
ref: "modules/diary/config_smoke_test.go#TestDailyDegradesSmoke"
|
||||
status: pass
|
||||
human_judgment: false
|
||||
- id: D5
|
||||
description: "Generated main installs diary (Bootstrap first, Setup after compass.Load); summer new writes config/log.yaml"
|
||||
requirement: D-10
|
||||
verification:
|
||||
- kind: unit
|
||||
ref: "internal/build/build_test.go#TestGenerateMainInstallsDiary"
|
||||
status: pass
|
||||
- kind: unit
|
||||
ref: "internal/build/new_golden_test.go#TestNewGolden"
|
||||
status: pass
|
||||
human_judgment: false
|
||||
- id: D6
|
||||
description: "River logs as component river and GORM as component db with parameterized SQL traces only at verbosity 3"
|
||||
requirement: D-09
|
||||
verification:
|
||||
- kind: unit
|
||||
ref: "modules/conga/logger_smoke_test.go#TestRiverLoggerUsesDiarySmoke"
|
||||
status: pass
|
||||
- kind: unit
|
||||
ref: "modules/lagoon/logger_smoke_test.go#TestGormLoggerUsesDiarySmoke"
|
||||
status: pass
|
||||
human_judgment: false
|
||||
- id: D7
|
||||
description: "Styled console lines on a real terminal look right in bonfire's palette (time, level colors, component prefix)"
|
||||
requirement: D-04
|
||||
verification: []
|
||||
human_judgment: true
|
||||
rationale: "Color rendering on a real terminal cannot be asserted by the short suite; a throwaway probe showed the expected ANSI sequences, plan 4 adds goldens"
|
||||
|
||||
duration: 30min
|
||||
completed: 2026-10-21
|
||||
status: complete
|
||||
---
|
||||
|
||||
# Phase 19.8 Plan 01: diary logging module Summary
|
||||
|
||||
**New `diary` module: Laravel-shaped `config/log.yaml` channels (console, stderr, daily, stack, null) with per-component levels, sunscreen on every channel, daily JSON files on by default, and River, GORM and every framework module logging through named component loggers.**
|
||||
|
||||
## Performance
|
||||
|
||||
- **Duration:** 30 min
|
||||
- **Started:** 2026-10-21T09:28:13Z
|
||||
- **Completed:** 2026-10-21T09:58:29Z
|
||||
- **Tasks:** 3
|
||||
- **Files modified:** 86 (code, docs and goldens; 2,414 insertions, 172 deletions)
|
||||
|
||||
## Accomplishments
|
||||
|
||||
- Decision note `.planning/notes/2026-10-21-console-charm-stack.md` and STACK.md rows committed first (D-02).
|
||||
- `modules/diary`: proxy component loggers safe in package vars, a lipgloss console handler in bonfire's palette with control-character stripping, a stdlib daily writer (0640 files, 0750 dirs, lazy open, retention, degrade-once), channels built as sunscreen-wrapped leaves under `slog.NewMultiHandler`, runtime `SetVerbosity` with quiet affecting only console channels.
|
||||
- `bonfire`: `ColorMode` (`ColorAuto`, `ColorAlways`, `ColorNever`), `Palette`, `DefaultPalette`, `DetectProfile`.
|
||||
- Generated main: `diary.Bootstrap(os.Stderr, diary.Options{})` as the first statement of `run`, `diary.Setup(cfg, diary.Options{})` after `compass.Load`; no sunscreen import. `examples/hello/main.go` regenerated. `summer new` writes `config/log.yaml`.
|
||||
- River through `diary.For("river")`, GORM through `logger.NewSlogLogger(diary.For("db"), ...)`, and every framework module through a package `moduleLog`; only surf's request log still uses the process default (plan 3).
|
||||
- Docs: `docs/services/logging.md` rewritten (Channels, config/log.yaml, Component loggers, Daily files, Redaction, Logging from a plugin), log keys in both configuration pages, READMEs for diary, bonfire, sunscreen, conga, lagoon and every module that now imports diary.
|
||||
|
||||
## Task Commits
|
||||
|
||||
1. **Planning doc (D-02)**: `e6039b4` docs(19.8): decide the charm v2 console stack
|
||||
2. **Task 1: tracer**: `e903cc3` feat(diary): component loggers through a redacting console and daily stack
|
||||
3. **Task 2: channels and config**: `5b09b32` feat(diary): channels, components and config/log.yaml
|
||||
4. **Task 3a: River and GORM**: `e6b20e2` feat(conga,lagoon): River and GORM log through diary components
|
||||
5. **Task 3b: framework modules**: `44291ad` refactor: framework modules log through diary components
|
||||
|
||||
`commits: 6` is measured from the ledger (`bde7d9f..44291ad`); one of the six, `71b9931` docs(19.5), belongs to another session that committed in between. This plan made five commits.
|
||||
|
||||
## Charm versions installed
|
||||
|
||||
- `charm.land/lipgloss/v2` v2.0.6 and `github.com/charmbracelet/colorprofile` v0.4.3 (direct requirements in go.mod).
|
||||
- Not installed yet (plan 2): `charm.land/bubbletea/v2` v2.1.0, `charm.land/bubbles/v2` v2.2.1, `charm.land/huh/v2` v2.0.3, `charm.land/fang/v2` v2.0.1. `go list -m -versions` on 2026-10-21 showed these as the newest tags.
|
||||
|
||||
## Exported names for plan 2
|
||||
|
||||
- **diary:** `For`, `Bootstrap(w io.Writer, opts Options)`, `Setup(cfg *compass.Config, opts Options) error`, `SetVerbosity(v int, quiet bool)`, `Verbosity() int`, `Reset()`, `Close() error`, `ParseConfig`, `DefaultConfig`, `NewConsoleHandler(w io.Writer, opts ConsoleOptions) slog.Handler`; types `Options{Verbosity, Quiet, Color, Root, Stderr, Environ, Now}`, `Config{Default, Level, Channels, Components}`, `ChannelConfig{Driver, Format, Path, Level, HasLevel, Days, Channels}`, `ConsoleOptions{Level, Profile, AddSource}`; constants `ComponentKey`, `DriverConsole`, `DriverStderr`, `DriverDaily`, `DriverStack`, `DriverNull`, `FormatAuto`, `FormatJSON`, `FormatLogfmt`, `DefaultKey`, `LevelKey`, `ChannelsKey`, `ComponentsKey`. All names match the plan.
|
||||
- **bonfire:** `ColorMode`, `ColorAuto`, `ColorAlways`, `ColorNever`, `Palette{Success, Current, Warning, Error, ErrorBold, Muted, Header}`, `DefaultPalette()`, `DetectProfile(w io.Writer, mode ColorMode, environ []string) colorprofile.Profile`. `output.go` unchanged.
|
||||
- Verbosity semantics for plan 2's flags: 1 lowers every component floor to at most info, 2 or more to debug, 3 or more adds source locations on styled console lines and GORM SQL traces (`gormLogger` reads `diary.Verbosity()` when the connection opens); quiet raises only console channels to warn. Before Bootstrap or Setup, `SetVerbosity` only changes what `Verbosity` returns; `Options.Verbosity`/`Options.Quiet` set a new setup's values.
|
||||
|
||||
## Files skipped because of other sessions
|
||||
|
||||
None. `git status` showed no other session's edits under `modules/` before Task 3 (the only foreign edits were `.planning/STATE.md`, `.planning/state.json`, `.msd/`, a 19.4.1 `.gitkeep`, and a 19.5 CONTEXT edit that was committed by its session meanwhile); none were staged.
|
||||
|
||||
## Decisions Made
|
||||
|
||||
See `key-decisions` in the front matter. The two worth a second look:
|
||||
|
||||
- **wristband and bouncer imports.** The plan's "every framework module" rule (D-09, acceptance criteria) makes `wristband` and `bouncer` import `diary`, which pulls `bonfire` and `compass` into modules documented as dependency-free leaves. The 2026-10-19 decision note says "wristband stays a protocol leaf: no ORM, no framework module". I followed the plan and amended both READMEs; reverting is two lines per module if the user prefers to keep them leaves (their log calls would then stay on the process default logger).
|
||||
- **Daily retention count.** `days: 14` keeps 14 files (today and 13 before), as Laravel's `days` does; the plan's wording ("more than days days old") would keep 15. The docs and README say which.
|
||||
|
||||
## Deviations from Plan
|
||||
|
||||
### Auto-fixed Issues
|
||||
|
||||
**1. [Rule 3 - Blocking] Supplied-root pin guard always failed**
|
||||
- **Found during:** start of execution
|
||||
- **Issue:** the orchestrator's pin script substituted the pinned path into its own unbound-placeholder sentinel (`''|'<pinned path>') PIN_STAGE=pin-unbound`), so it reported `pin-unbound` FATAL for the correct root.
|
||||
- **Fix:** ran a scratchpad copy with only that sentinel restored to the literal `{PINNED_ROOT}`; every real check (actual toplevel against the pinned toplevel) unchanged and passing before each write and commit. The orchestrator's script was not modified.
|
||||
|
||||
**2. [Rule 3 - Blocking] TestNewGolden pins a fixed file list**
|
||||
- **Found during:** Task 2
|
||||
- **Fix:** added `config/log.yaml` to the list in `internal/build/new_golden_test.go` (not in the plan's file list) so `config__log.yaml.golden` is created and checked.
|
||||
|
||||
**3. [Rule 3 - Blocking] Go fences in docs need a src= reference**
|
||||
- **Found during:** Task 2 (docs checker)
|
||||
- **Fix:** added `modules/diary/example_test.go` (`ExampleFor`, runnable with output; package var `blogLog`) and referenced it from `docs/services/logging.md` with `src=`; shortened the page's front-matter description below 160 characters.
|
||||
|
||||
**4. [Rule 2 - CLAUDE.md docs rule] READMEs of every module that now imports diary**
|
||||
- **Found during:** Task 3
|
||||
- **Fix:** Dependencies sections of cabana, cooler, postcard, beachcomber, lighthouse, flare, phrasebook, wristband and bouncer list `diary`; postcard's `NewLogDriver` row and doc comment, and the `Logger()` doc comments of beachcomber, lighthouse and flare, describe the new fallback. Not in the plan's file list.
|
||||
|
||||
**5. [Rule 1 - Bug] gofmt import order in console.go**
|
||||
- **Found during:** Task 2; the Task 1 commit had an unsorted import block in `modules/diary/console.go`, fixed by `gofmt -w` in the Task 2 commit.
|
||||
|
||||
**6. Example modules' go.mod/go.sum left unchanged**
|
||||
- **Plan said:** run `go mod tidy` in the examples/hello modules whose build asks for go.sum entries (files list names hello and greeter go.sum).
|
||||
- **Found:** inside the repository's go.work every example build and test passes without changes; `go mod tidy` there only pulled pre-existing drift (aws-sdk and others, and dropped a toolchain line). Reverted; recorded in `deferred-items.md`.
|
||||
|
||||
**7. Tracer test logs two records to the daily file**
|
||||
- The plan's tracer asserts "a single JSON line"; the same test also logs from the pre-setup package-var logger (as the plan asks), so the daily file holds two lines and the test checks the first one.
|
||||
|
||||
---
|
||||
|
||||
**Total deviations:** 7 (3 blocking fixes, 1 docs rule, 1 formatting fix, 2 recorded differences). **Impact:** none on the plan's API names or behaviour; extra README updates keep the documentation rule.
|
||||
|
||||
## Issues Encountered
|
||||
|
||||
- `TestOIDCSubjectIsRandomSmoke` (wristband) failed once: the random subject contained `ada`, which the test rejects as the fixture user's name. Pre-existing flake, passed on rerun; logged in `deferred-items.md`.
|
||||
|
||||
## Known Stubs
|
||||
|
||||
None.
|
||||
|
||||
## Threat Flags
|
||||
|
||||
None beyond the plan's threat model: daily files under the application root (T-19.8-04, T-19.8-05, T-19.8-06), redaction on every leaf including stderr and null (T-19.8-01), parameterized GORM traces (T-19.8-02), control-character stripping on the console (T-19.8-03).
|
||||
|
||||
## Verification
|
||||
|
||||
- `go vet ./...`: clean.
|
||||
- `go test -count=1 -short ./...`: green (after the one wristband flake rerun).
|
||||
- `go -C examples/hello vet ./...` and `go -C examples/hello test -count=1 ./...`: green.
|
||||
- `TestDiaryTracerSmoke`, `TestConfigEnvSmoke`, `TestDailyDegradesSmoke`, `TestRiverLoggerUsesDiarySmoke`, `TestGormLoggerUsesDiarySmoke`: `--- PASS` by name.
|
||||
- `TestDocsTree` and `summer docs:build --check`: no problems.
|
||||
- Acceptance criteria of all three tasks re-run: pass (no `slog.Default()` or package-level `slog.Info/Warn/Error/Debug` calls left in non-test framework code outside diary and surf's access log; only bonfire and diary import charm modules; nothing imports `gopkg.in/yaml.v3`; no consuming application named).
|
||||
- Nothing pushed or tagged.
|
||||
|
||||
## Next Phase Readiness
|
||||
|
||||
Ready for 19.8-02: global flags call `diary.SetVerbosity`, the bonfire widgets move onto `Palette`/`DetectProfile`, and plan 2 installs the remaining four charm modules.
|
||||
|
||||
## Self-Check: PASSED
|
||||
@@ -0,0 +1,9 @@
|
||||
# Phase 19.8 deferred items
|
||||
|
||||
Out-of-scope findings recorded during execution. Not fixed in this phase.
|
||||
|
||||
## Found during 19.8-01
|
||||
|
||||
- **Flaky wristband test.** `TestOIDCSubjectIsRandomSmoke` (`modules/wristband/oidc_security_test.go:151`) rejects a subject that contains `ada` (to catch the fixture user's name), but a random UUIDv4 contains `ada` in about 0.7% of runs. It failed once during the 19.8-01 short suite (`sub = "64a89757-94a7-4699-bf28-4329d8c7eada"`) and passed on three reruns. Fix: compare against the fixture's name as a whole, or check that the subject differs from it, instead of matching a substring of hex.
|
||||
- **Pre-existing gofmt drift.** `gofmt -l` lists `internal/build/registry.go`, `modules/cabana/account_tokens.go` (no newline at end of file) and some test files (`modules/cabana/*_test.go`, `modules/compass/*_test.go`, `modules/tide/*_test.go`). Unchanged by this plan beyond the logger lines.
|
||||
- **examples/hello go.mod is stale outside the workspace.** `GOWORK=off go -C examples/hello build .` asks for `go mod tidy`: its go.mod lacks requirements the framework already had before this phase (aws-sdk, bluemonday, redis, among others). Inside the repository's go.work every build and test passes, so the example modules' go.mod and go.sum were left as they were.
|
||||
Reference in New Issue
Block a user