template/pkg/logger/handler.go
djmil 5ec8e6999a pkg/logger: human handler UX— colon format- debug mode- dedup counter
Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com>
2026-06-03 18:48:51 +00:00

313 lines
8.1 KiB
Go
Raw Blame History

This file contains ambiguous Unicode characters

This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.

package logger
import (
"context"
"fmt"
"io"
"log/slog"
"os"
"strconv"
"strings"
"sync"
"time"
)
// isTerminal reports whether f is connected to a character device (terminal).
func isTerminal(f *os.File) bool {
info, err := f.Stat()
return err == nil && info.Mode()&os.ModeCharDevice != 0
}
// writeState holds shared mutable display state for a humanHandler family.
// Shared via pointer across parent and all derived handlers (WithAttrs, WithGroup)
// so that a child-logger INFO write correctly commits a parent-started debug line.
type writeState struct {
mu sync.Mutex
lastDebug string // original message text used for deduplication comparison
lastDisplay string // display form stored for counter rewrites (msg or msg+...)
debugN int // consecutive repeat count (0 = no pending debug line)
pendingNL bool // true when last write was a debug line without trailing newline
}
// humanHandler writes human-readable log lines to w with no timestamp.
//
// Two operating modes, selected by handler level at construction:
//
// Normal mode (level > DEBUG):
//
// INFO: message... "..." signals hidden structured fields (see debug file)
// INFO: message (no suffix when no fields)
// WARN: warning: msg: k=v, … always full fields — needs immediate visibility
// ERROR: error: msg: k=v, … always full fields — needs immediate visibility
//
// Debug mode (level <= DEBUG):
//
// DEBUG: debug: message... fields hidden; identical consecutive messages collapse:
// debug: message... ×N live counter updated in-place with \r
// INFO: message: k=v, … full fields — debug mode dumps everything
// WARN: warning: msg: k=v, …
// ERROR: error: msg: k=v, …
type humanHandler struct {
w io.Writer
level slog.Level
state *writeState // shared with all derived handlers
attrs []slog.Attr
prefix string
}
func newHumanHandler(w io.Writer, level slog.Level) *humanHandler {
return &humanHandler{w: w, level: level, state: &writeState{}}
}
func (h *humanHandler) debugMode() bool { return h.level <= slog.LevelDebug }
func (h *humanHandler) Enabled(_ context.Context, level slog.Level) bool {
return level >= h.level
}
func (h *humanHandler) Handle(_ context.Context, r slog.Record) error {
h.state.mu.Lock()
defer h.state.mu.Unlock()
switch {
case r.Level < slog.LevelInfo:
return h.handleDebug(r)
case r.Level < slog.LevelWarn:
return h.handleInfo(r)
default:
return h.handleImportant(r)
}
}
// handleDebug shows message + "..." if fields, with live deduplication counter.
// Fields are suppressed on screen even in debug mode — they change per iteration
// and would make the counter rewrite misleading; full values are in the debug file.
// Assumes state.mu is held.
func (h *humanHandler) handleDebug(r slog.Record) error {
display := h.ellipsis(r)
if r.Message == h.state.lastDebug {
h.state.debugN++
_, err := fmt.Fprintf(h.w, "\r%s ×%d", h.state.lastDisplay, h.state.debugN)
return err
}
if err := h.commitPending(); err != nil {
return err
}
h.state.lastDebug = r.Message
h.state.lastDisplay = display
h.state.debugN = 1
h.state.pendingNL = true
_, err := fmt.Fprintf(h.w, "%s", display)
return err
}
// handleInfo shows the full line in debug mode; hides fields with "..." in normal mode.
// Assumes state.mu is held.
func (h *humanHandler) handleInfo(r slog.Record) error {
if err := h.commitPending(); err != nil {
return err
}
var line string
if h.debugMode() {
line = h.fullLine(r)
} else {
line = h.ellipsis(r)
}
_, err := fmt.Fprintf(h.w, "%s\n", line)
return err
}
// handleImportant always shows the full line — WARN and ERROR need immediate full visibility.
// Assumes state.mu is held.
func (h *humanHandler) handleImportant(r slog.Record) error {
if err := h.commitPending(); err != nil {
return err
}
_, err := fmt.Fprintf(h.w, "%s\n", h.fullLine(r))
return err
}
func (h *humanHandler) commitPending() error {
if h.state.pendingNL {
h.state.pendingNL = false
h.state.lastDebug = ""
h.state.lastDisplay = ""
h.state.debugN = 0
_, err := io.WriteString(h.w, "\n")
return err
}
return nil
}
// fullLine builds "prefix message: k=v, k=v" with all structured fields.
func (h *humanHandler) fullLine(r slog.Record) string {
var b strings.Builder
b.WriteString(humanLevel(r.Level))
b.WriteString(r.Message)
var parts []string
for _, a := range h.attrs {
collectAttr(&parts, h.prefix, a)
}
r.Attrs(func(a slog.Attr) bool {
collectAttr(&parts, h.prefix, a)
return true
})
if len(parts) > 0 {
b.WriteString(": ")
b.WriteString(strings.Join(parts, ", "))
}
return b.String()
}
// ellipsis builds "prefix message" with "..." appended when structured fields exist.
func (h *humanHandler) ellipsis(r slog.Record) string {
hasFields := len(h.attrs) > 0
if !hasFields {
r.Attrs(func(_ slog.Attr) bool {
hasFields = true
return false
})
}
s := humanLevel(r.Level) + r.Message
if hasFields {
s += "..."
}
return s
}
// flush commits any pending debug line by writing the trailing newline.
// Called via Logger.Close() before process exit.
func (h *humanHandler) flush() {
h.state.mu.Lock()
defer h.state.mu.Unlock()
if h.state.pendingNL {
h.state.pendingNL = false
_, _ = io.WriteString(h.w, "\n")
}
}
func (h *humanHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
merged := make([]slog.Attr, len(h.attrs)+len(attrs))
copy(merged, h.attrs)
copy(merged[len(h.attrs):], attrs)
return &humanHandler{w: h.w, level: h.level, state: h.state, attrs: merged, prefix: h.prefix}
}
func (h *humanHandler) WithGroup(name string) slog.Handler {
if name == "" {
return h
}
prefix := h.prefix
if prefix != "" {
prefix += "."
}
return &humanHandler{w: h.w, level: h.level, state: h.state, attrs: h.attrs, prefix: prefix + name}
}
// multiHandler fans a single log record out to multiple handlers.
// Each sub-handler's own Enabled filter is respected independently.
type multiHandler []slog.Handler
func (m multiHandler) Enabled(ctx context.Context, level slog.Level) bool {
for _, h := range m {
if h.Enabled(ctx, level) {
return true
}
}
return false
}
func (m multiHandler) Handle(ctx context.Context, r slog.Record) error {
var firstErr error
for _, h := range m {
if h.Enabled(ctx, r.Level) {
if err := h.Handle(ctx, r); err != nil && firstErr == nil {
firstErr = err
}
}
}
return firstErr
}
func (m multiHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
handlers := make(multiHandler, len(m))
for i, h := range m {
handlers[i] = h.WithAttrs(attrs)
}
return handlers
}
func (m multiHandler) WithGroup(name string) slog.Handler {
handlers := make(multiHandler, len(m))
for i, h := range m {
handlers[i] = h.WithGroup(name)
}
return handlers
}
func (m multiHandler) flush() {
for _, h := range m {
if f, ok := h.(interface{ flush() error }); ok {
_ = f.flush()
}
}
}
// ── formatting helpers ────────────────────────────────────────────────────────
func humanLevel(level slog.Level) string {
switch {
case level >= slog.LevelError:
return "error: "
case level >= slog.LevelWarn:
return "warning: "
case level >= slog.LevelInfo:
return "" // INFO needs no label — it is the program's normal voice
default:
return "debug: "
}
}
func collectAttr(out *[]string, prefix string, a slog.Attr) {
a.Value = a.Value.Resolve()
if a.Value.Kind() == slog.KindGroup {
sub := prefix
if a.Key != "" {
if sub != "" {
sub += "."
}
sub += a.Key
}
for _, ga := range a.Value.Group() {
collectAttr(out, sub, ga)
}
return
}
if a.Key == "" {
return
}
key := a.Key
if prefix != "" {
key = prefix + "." + key
}
var vb strings.Builder
appendValue(&vb, a.Value)
*out = append(*out, key+"="+vb.String())
}
func appendValue(b *strings.Builder, v slog.Value) {
switch v.Kind() {
case slog.KindString:
s := v.String()
if strings.ContainsAny(s, " \t\n\"=") {
b.WriteString(strconv.Quote(s))
} else {
b.WriteString(s)
}
case slog.KindTime:
b.WriteString(v.Time().Format(time.RFC3339))
default:
fmt.Fprint(b, v.Any())
}
}