From 3520d5d4800fced8bd505f114948efad04f9213f Mon Sep 17 00:00:00 2001 From: Jakub Zych Date: Wed, 28 Oct 2026 20:41:07 +0100 Subject: [PATCH] fix(diary): skip HideOnTTY records only on a terminal console, also with forced color (IN-01, quick-261028-rqd) --- docs/console/setup-and-maintenance.md | 2 +- modules/diary/README.md | 2 +- modules/diary/console.go | 36 ++++++++++++++++---------- modules/diary/console_internal_test.go | 36 ++++++++++++++++++++++++++ modules/diary/diary.go | 3 ++- modules/diary/diary_test.go | 6 +++-- modules/surf/summary_test.go | 11 +++++--- scripts/check-phase19.8.sh | 2 ++ 8 files changed, 75 insertions(+), 23 deletions(-) create mode 100644 modules/diary/console_internal_test.go diff --git a/docs/console/setup-and-maintenance.md b/docs/console/setup-and-maintenance.md index 91c76cba..468419d5 100644 --- a/docs/console/setup-and-maintenance.md +++ b/docs/console/setup-and-maintenance.md @@ -101,7 +101,7 @@ SummerCMS acme v1.4.0 (framework v0.4.0) The database line shows the host, port and database name, never the user or password. Pending migrations read `3 pending — run bin/acme migrate`. The admin line shows the admin URL, or `off` with the steps to add an admin controller; a warning naming `summer admin:create` follows when the `backend_users` table is empty. `-v` adds one line per plugin with the plugins it requires and its pending migrations, and lets every component's info logs through; `-q` prints no summary, only warnings and errors. -Off a terminal (systemd, Docker, a redirected log) nothing is printed on stdout: the same facts are logged as one `startup summary` record and one record whose message is exactly `listening on `, both from the `serve` component, so journald and the daily files keep them and scripts can wait for the second one. On a terminal the console does not repeat the two records after the block; a file channel whose level lets Info through still gets them (the default daily channel keeps only warnings and errors). +Off a terminal (systemd, Docker, a redirected log) nothing is printed on stdout: the same facts are logged as one `startup summary` record and one record whose message is exactly `listening on `, both from the `serve` component, so journald and the daily files keep them and scripts can wait for the second one. On a terminal the console does not repeat the two records after the block; a redirected stderr keeps them, also with `--ansi` or `FORCE_COLOR`; a file channel whose level lets Info through still gets them (the default daily channel keeps only warnings and errors). ### Shutting down diff --git a/modules/diary/README.md b/modules/diary/README.md index b94b8d37..e1cc3732 100644 --- a/modules/diary/README.md +++ b/modules/diary/README.md @@ -89,7 +89,7 @@ Tests that set diary up restore the previous process logger with `t.Cleanup(diar | `diary.FromGlobals` | Returns the `diary.Options` (verbosity, quiet, color mode) of the console global options in a `bonfire.Globals`. | | `diary.ApplyGlobals` | Applies parsed `bonfire.Globals` to the running setup: verbosity and quiet, and the console color mode when it changed. | | `diary.Verbosity` | Returns the current verbosity. | -| `diary.HideOnTTY` | Marks a context so a console channel writing to a terminal skips the records logged with it; files, stderr channels and a console that is not a terminal still write them. Used for facts a command has just printed as a block, such as `serve`'s startup summary. | +| `diary.HideOnTTY` | Marks a context so a console channel writing to a terminal skips the records logged with it; files, stderr channels and a console that is not a terminal (also one with forced color, `--ansi` or `FORCE_COLOR`) still write them. Used for facts a command has just printed as a block, such as `serve`'s startup summary. | | `diary.Reset` | Drops the setup, closes its files and restores the process default logger captured at the first setup. | | `diary.Close` | Closes the open daily files; later records open them again. | | `diary.Options` | Setup options: `Verbosity`, `Quiet`, `Color`, `Root`, `Stderr`, `Environ` and `Now`. | diff --git a/modules/diary/console.go b/modules/diary/console.go index 2792b23d..02e7c751 100644 --- a/modules/diary/console.go +++ b/modules/diary/console.go @@ -40,7 +40,9 @@ type ConsoleOptions struct { // the message and attribute values, so logged data cannot inject terminal // escape sequences. Each line is written with one Write call, serialized // across the handler and its WithAttrs and WithGroup clones; while a bonfire -// live view runs, lines print above it through bonfire.PrintAbove. +// live view runs, lines print above it through bonfire.PrintAbove. Records +// marked with HideOnTTY are skipped only when w is a terminal (checked once +// here), so forced color on a redirected stream keeps them. func NewConsoleHandler(w io.Writer, opts ConsoleOptions) slog.Handler { source := new(atomic.Bool) source.Store(opts.AddSource) @@ -53,11 +55,12 @@ func newConsoleHandler(w io.Writer, opts ConsoleOptions, source *atomic.Bool) *c level = slog.LevelInfo } return &consoleHandler{ - out: &colorprofile.Writer{Forward: w, Profile: opts.Profile}, - mu: new(sync.Mutex), - level: level, - source: source, - palette: bonfire.DefaultPalette(), + out: &colorprofile.Writer{Forward: w, Profile: opts.Profile}, + terminal: isTerminal(w), + mu: new(sync.Mutex), + level: level, + source: source, + palette: bonfire.DefaultPalette(), } } @@ -67,11 +70,15 @@ type consoleAttr struct { } type consoleHandler struct { - out io.Writer - mu *sync.Mutex - level slog.Leveler - source *atomic.Bool - palette bonfire.Palette + out io.Writer + mu *sync.Mutex + level slog.Leveler + source *atomic.Bool + palette bonfire.Palette + // terminal is true when the handler's writer is a terminal, checked + // once when the handler is built: only then are HideOnTTY records + // skipped. + terminal bool component string attrs []consoleAttr groups []string @@ -114,9 +121,10 @@ func (h *consoleHandler) WithGroup(name string) slog.Handler { } func (h *consoleHandler) Handle(ctx context.Context, r slog.Record) error { - // The styled console is read by a person; facts already shown as a - // block (HideOnTTY) are not repeated as log lines. - if hiddenOnTTY(ctx) { + // A console on a terminal is read by a person; facts already shown as + // a block (HideOnTTY) are not repeated as log lines. Forced color on a + // redirected stream keeps them. + if h.terminal && hiddenOnTTY(ctx) { return nil } component := h.component diff --git a/modules/diary/console_internal_test.go b/modules/diary/console_internal_test.go new file mode 100644 index 00000000..4a6f6d85 --- /dev/null +++ b/modules/diary/console_internal_test.go @@ -0,0 +1,36 @@ +package diary + +import ( + "bytes" + "context" + "log/slog" + "strings" + "sync/atomic" + "testing" + "time" + + "github.com/charmbracelet/colorprofile" +) + +// TestConsoleHideOnTTYTerminal (IN-01): the styled console handler skips a +// HideOnTTY record when its writer is a terminal, and writes ordinary +// records. +func TestConsoleHideOnTTYTerminal(t *testing.T) { + var buf bytes.Buffer + h := newConsoleHandler(&buf, ConsoleOptions{Profile: colorprofile.ANSI}, new(atomic.Bool)) + h.terminal = true + hidden := slog.NewRecord(time.Time{}, slog.LevelInfo, "hidden summary", 0) + if err := h.Handle(HideOnTTY(context.Background()), hidden); err != nil { + t.Fatal(err) + } + shown := slog.NewRecord(time.Time{}, slog.LevelInfo, "shown line", 0) + if err := h.Handle(context.Background(), shown); err != nil { + t.Fatal(err) + } + if strings.Contains(buf.String(), "hidden summary") { + t.Errorf("terminal console shows a HideOnTTY record:\n%s", buf.String()) + } + if !strings.Contains(buf.String(), "shown line") { + t.Errorf("terminal console lacks the ordinary record:\n%s", buf.String()) + } +} diff --git a/modules/diary/diary.go b/modules/diary/diary.go index 4fdbbbb3..9bfa22c4 100644 --- a/modules/diary/diary.go +++ b/modules/diary/diary.go @@ -244,7 +244,8 @@ type hideOnTTYKey struct{} // HideOnTTY marks ctx so that a console channel writing to a terminal skips // the records logged with it (Logger.InfoContext and the like); daily files, -// stderr channels and a console that is not a terminal still write them. A +// stderr channels and a console that is not a terminal still write them, +// also when color is forced (--ansi, FORCE_COLOR) on a redirected stream. A // command that has just printed the same facts as a styled block (serve's // startup summary) logs them with it, so a person does not read them twice // while journald and the log files keep them. diff --git a/modules/diary/diary_test.go b/modules/diary/diary_test.go index b83c2f9e..718309dd 100644 --- a/modules/diary/diary_test.go +++ b/modules/diary/diary_test.go @@ -357,8 +357,10 @@ func TestHideOnTTY(t *testing.T) { blog := diary.For("blog") blog.InfoContext(ctx, "hidden summary") blog.Info("shown line") - if strings.Contains(styled.String(), "hidden summary") { - t.Errorf("styled console shows a HideOnTTY record:\n%s", styled.String()) + // IN-01: forced color on a writer that is not a terminal keeps the + // HideOnTTY records; only a terminal console skips them. + if !strings.Contains(styled.String(), "hidden summary") { + t.Errorf("styled console off a terminal dropped a HideOnTTY record:\n%s", styled.String()) } if !strings.Contains(styled.String(), "shown line") { t.Errorf("styled console lacks the ordinary record:\n%s", styled.String()) diff --git a/modules/surf/summary_test.go b/modules/surf/summary_test.go index 757bef34..35e1b4b7 100644 --- a/modules/surf/summary_test.go +++ b/modules/surf/summary_test.go @@ -174,7 +174,9 @@ func TestServeRecords(t *testing.T) { t.Errorf("admin warning record missing:\n%s", logs.String()) } - // HideOnTTY: hidden on a styled console, kept in the daily file. + // HideOnTTY: hidden only on a terminal console (diary's + // TestConsoleHideOnTTYTerminal), kept in the daily file and, since + // IN-01, on a styled console that is not a terminal (forced color). root := t.TempDir() cfg, err := compass.Open(compass.Options{Dir: t.TempDir(), Environ: []string{"SUMMER_LOG__CHANNELS__DAILY__LEVEL=info"}}) if err != nil { @@ -187,11 +189,12 @@ func TestServeRecords(t *testing.T) { t.Fatal(err) } logSummary(diary.HideOnTTY(context.Background()), serveLog, f) - if strings.Contains(console.String(), summaryMessage) || strings.Contains(console.String(), "listening on") { - t.Errorf("styled console shows the hidden records:\n%s", console.String()) + if !strings.Contains(console.String(), summaryMessage) || !strings.Contains(console.String(), "listening on") { + t.Errorf("forced-color console off a terminal dropped the HideOnTTY records:\n%s", console.String()) } + before := len(console.String()) logSummary(context.Background(), serveLog, f) - if !strings.Contains(console.String(), "listening on :8096") { + if !strings.Contains(console.String()[before:], "listening on :8096") { t.Errorf("styled console lacks the records logged without HideOnTTY:\n%s", console.String()) } if err := diary.Close(); err != nil { diff --git a/scripts/check-phase19.8.sh b/scripts/check-phase19.8.sh index df6283cd..64789a16 100755 --- a/scripts/check-phase19.8.sh +++ b/scripts/check-phase19.8.sh @@ -102,6 +102,8 @@ DIARY_TESTS=( # Plan 05 (review fixes): daily retry, retired writers (WR-04, WR-06). TestDailyRetriesAfterFailure TestRetiredDailyWriterKeepsNoFile TestApplyGlobalsRebuildsOnce + # quick 261028-rqd (info findings): IN-01. + TestConsoleHideOnTTYTerminal ) SUNSCREEN_TESTS=( # Plan 04: the compatibility entry point.