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

@@ -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 <addr>`, 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 <addr>`, 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
 

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`. |

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

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())
+	}
+}

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.

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())

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 {

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.