pkg/logger: replace NewDevelopment with NewCLI(level, debugFile)

Two modes for interactive CLI use — driven by debugFile presence:
- Normal (debugFile=""): human text on screen, INFO and above.
- Debug  (debugFile set): same screen + full JSON trace to file.

Auto-detects TTY; falls back to 12-factor JSON when piped/redirected.
IsInteractive() exposes TTY detection for call sites that need it.

Terminal format: INFO has no prefix (program's normal voice);
WARN prints "warning: …"; ERROR prints "error: …"; DEBUG "debug: …".

Breaking: NewDevelopment removed.

Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com>
This commit is contained in:
djmil 2026-06-03 14:14:19 +00:00
parent 1054f3fd6b
commit 7bc91b0890
6 changed files with 411 additions and 31 deletions

View File

@ -20,6 +20,7 @@ type AppConfig struct {
// LoggerConfig controls logging behavior.
type LoggerConfig struct {
Level string // debug | info | warn | error
DebugFile string // non-empty enables debug mode: writes full JSON trace to this path
}
// Greeter config for internal/greeter/Service.
@ -41,6 +42,7 @@ func parseArgs() *Config {
port := flag.Int("port", 8080, "listen port")
env := flag.String("env", "dev", "environment: dev | staging | prod")
level := flag.String("log-level", "info", "log level: debug | info | warn | error")
debugLog := flag.String("debug-log", "", "write full debug trace to file (enables debug mode)")
flag.Parse()
@ -51,6 +53,7 @@ func parseArgs() *Config {
},
Logger: LoggerConfig{
Level: *level,
DebugFile: *debugLog,
},
Greeter: GreeterConfig{
Name: *name,

View File

@ -22,11 +22,12 @@ type app struct {
}
func newApp(cfg *Config) *app {
var log *logger.Logger
// NewCLI auto-detects: human text on a terminal, JSON when piped.
// Pass -debug-log FILE to enable debug mode (writes full trace to file).
log := logger.NewCLI(cfg.Logger.Level, cfg.Logger.DebugFile).Expect("create logger")
log.Debug("config", "port", cfg.App.Port, "level", cfg.Logger.Level, "env", cfg.App.Env)
if cfg.App.Env == "dev" {
log = logger.NewDevelopment()
} else {
log = logger.New(cfg.Logger.Level).Expect("create logger") // might fail dramatically
log.Warn("dev mode — not for production")
}
return &app{
cfg: cfg,
@ -54,11 +55,8 @@ func main() {
}
func (a *app) run() {
// High level business logic goes here
a.log.Debug("processing", "name", a.cfg.Greeter.Name)
a.showGreeting(a.cfg.Greeter.Name)
// Human readable messages.
// Use logs for presenting technical data in machine friendly format.
fmt.Printf("TODO: implement listening on port %d\n", a.cfg.App.Port)
}

183
pkg/logger/handler.go Normal file
View File

@ -0,0 +1,183 @@
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
}
// humanHandler writes human-readable log lines to w with no timestamp.
//
// Format:
//
// INFO: message key=val … (no prefix — the program's normal voice)
// WARN: warning: message key=val …
// ERROR: error: message key=val …
// DEBUG: debug: message key=val …
type humanHandler struct {
w io.Writer
level slog.Level
mu sync.Mutex
attrs []slog.Attr
prefix string // dot-separated group prefix for attribute keys
}
func newHumanHandler(w io.Writer, level slog.Level) *humanHandler {
return &humanHandler{w: w, level: level}
}
func (h *humanHandler) Enabled(_ context.Context, level slog.Level) bool {
return level >= h.level
}
func (h *humanHandler) Handle(_ context.Context, r slog.Record) error {
var b strings.Builder
b.WriteString(humanLevel(r.Level))
b.WriteString(r.Message)
for _, a := range h.attrs {
appendAttr(&b, h.prefix, a)
}
r.Attrs(func(a slog.Attr) bool {
appendAttr(&b, h.prefix, a)
return true
})
b.WriteByte('\n')
h.mu.Lock()
defer h.mu.Unlock()
_, err := io.WriteString(h.w, b.String())
return err
}
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, 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, 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,
// so different handlers can capture different level ranges.
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
}
// ── 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 appendAttr(b *strings.Builder, prefix string, a slog.Attr) {
a.Value = a.Value.Resolve()
if a.Value.Kind() == slog.KindGroup {
// inline unnamed groups; named groups become a key prefix
sub := prefix
if a.Key != "" {
if sub != "" {
sub += "."
}
sub += a.Key
}
for _, ga := range a.Value.Group() {
appendAttr(b, sub, ga)
}
return
}
if a.Key == "" {
return
}
key := a.Key
if prefix != "" {
key = prefix + "." + key
}
b.WriteByte(' ')
b.WriteString(key)
b.WriteByte('=')
appendValue(b, a.Value)
}
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())
}
}

121
pkg/logger/handler_test.go Normal file
View File

@ -0,0 +1,121 @@
package logger
import (
"log/slog"
"strings"
"testing"
)
func TestHumanLevel(t *testing.T) {
tests := []struct {
level slog.Level
want string
}{
{slog.LevelDebug, "debug: "},
{slog.LevelInfo, ""},
{slog.LevelWarn, "warning: "},
{slog.LevelError, "error: "},
{slog.LevelError + 4, "error: "},
}
for _, tc := range tests {
if got := humanLevel(tc.level); got != tc.want {
t.Errorf("humanLevel(%v) = %q, want %q", tc.level, got, tc.want)
}
}
}
func TestHumanHandlerInfoNoPrefix(t *testing.T) {
var buf strings.Builder
h := newHumanHandler(&buf, slog.LevelDebug)
slog.New(h).Info("hello world")
if got := strings.TrimRight(buf.String(), "\n"); got != "hello world" {
t.Errorf("got %q, want %q", got, "hello world")
}
}
func TestHumanHandlerPrefixes(t *testing.T) {
tests := []struct {
fn func(*slog.Logger, string, ...any)
want string
}{
{(*slog.Logger).Warn, "warning: "},
{(*slog.Logger).Error, "error: "},
}
for _, tc := range tests {
var buf strings.Builder
log := slog.New(newHumanHandler(&buf, slog.LevelDebug))
tc.fn(log, "msg")
if !strings.HasPrefix(buf.String(), tc.want) {
t.Errorf("got %q, want prefix %q", buf.String(), tc.want)
}
}
}
func TestHumanHandlerAttrs(t *testing.T) {
var buf strings.Builder
slog.New(newHumanHandler(&buf, slog.LevelDebug)).Info("started", "port", 8080)
want := "started port=8080\n"
if got := buf.String(); got != want {
t.Errorf("got %q, want %q", got, want)
}
}
func TestHumanHandlerStringQuoting(t *testing.T) {
var buf strings.Builder
slog.New(newHumanHandler(&buf, slog.LevelDebug)).Warn("check", "msg", "Hello, Gopher!")
if !strings.Contains(buf.String(), `msg="Hello, Gopher!"`) {
t.Errorf("expected quoted value in %q", buf.String())
}
}
func TestHumanHandlerWithAttrs(t *testing.T) {
var buf strings.Builder
h := newHumanHandler(&buf, slog.LevelDebug).WithAttrs([]slog.Attr{slog.String("rid", "abc")})
slog.New(h).Info("request")
if !strings.Contains(buf.String(), "rid=abc") {
t.Errorf("pre-set attr missing: %q", buf.String())
}
}
func TestHumanHandlerLevelFiltering(t *testing.T) {
var buf strings.Builder
log := slog.New(newHumanHandler(&buf, slog.LevelWarn))
log.Info("dropped")
log.Warn("kept")
if strings.Contains(buf.String(), "dropped") {
t.Error("INFO line should have been filtered at WARN level")
}
if !strings.Contains(buf.String(), "kept") {
t.Error("WARN line should appear")
}
}
func TestMultiHandlerFanOut(t *testing.T) {
var screen, file strings.Builder
// screen: INFO+, file: DEBUG+
m := multiHandler{
newHumanHandler(&screen, slog.LevelInfo),
slog.NewJSONHandler(&file, &slog.HandlerOptions{Level: slog.LevelDebug}),
}
log := slog.New(m)
log.Debug("trace", "k", "v")
log.Info("event", "k", "v")
if strings.Contains(screen.String(), "trace") {
t.Error("DEBUG should not appear on screen")
}
if !strings.Contains(screen.String(), "event") {
t.Error("INFO should appear on screen")
}
if !strings.Contains(file.String(), "trace") {
t.Error("DEBUG should appear in file")
}
if !strings.Contains(file.String(), "event") {
t.Error("INFO should appear in file")
}
}

View File

@ -1,16 +1,26 @@
// Package logger wraps log/slog with a thin, ergonomic API.
//
// Per the Twelve-Factor App (factor XI), the application writes structured log
// events to stderr and never manages log files or routing itself. The execution
// environment (shell, systemd, Docker) is responsible for capturing and storing
// the stream. Human-readable output belongs on stdout via fmt.Print*.
// Design principle: call sites express what is logged, not how it reaches the
// reader. The constructor picks the right format for the execution environment;
// application code never changes.
//
// Typical use:
// Per the Twelve-Factor App (factor XI), logs are written to stderr as an
// unbuffered stream. The execution environment (shell, systemd, Docker, k8s)
// routes and stores the stream.
//
// log := logger.New("info").Expect("create logger")
// Two constructors write to stderr:
//
// - New(level) — JSON, 12-factor compatible; use for headless services.
// - NewCLI(level, debugFile) — auto-detects: human text on a terminal, JSON when piped.
// Providing a non-empty debugFile enables debug mode: DEBUG writes to that
// file as JSON; the screen always shows INFO and above.
//
// Typical use in a CLI application:
//
// log := logger.NewCLI("info", "").Expect("create logger")
// log.Info("server started", "port", 8080)
//
// // child logger for request-scoped fields that repeat across many lines:
// // child logger with request-scoped fields:
// req := log.WithField("request_id", rid)
// req.Info("start")
// req.Info("end")
@ -38,6 +48,7 @@ type Logger struct {
}
// New creates a JSON logger writing to stderr for the given level string.
// Use for headless services; prefer NewCLI for programs invoked by a human.
// Valid levels: debug, info, warn, error.
func New(level string) result.Expect[*Logger] {
lvl := parseLevel(level)
@ -45,18 +56,60 @@ func New(level string) result.Expect[*Logger] {
return result.Errw[*Logger](lvl.Err(), "parse log level")
}
handler := slog.NewJSONHandler(os.Stderr, &slog.HandlerOptions{Level: lvl.Value()})
logger := &Logger{slog.New(handler)}
return result.Ok(logger)
h := slog.NewJSONHandler(os.Stderr, &slog.HandlerOptions{Level: lvl.Value()})
return result.Ok(&Logger{slog.New(h)})
}
// NewDevelopment creates a human-friendly text logger writing to stderr at debug level.
// Use this in local dev; prefer New() in any deployed environment.
func NewDevelopment() *Logger {
h := slog.NewTextHandler(os.Stderr, &slog.HandlerOptions{Level: slog.LevelDebug})
// NewCLI creates a logger for programs invoked by a human operator.
//
// When stderr is a terminal it operates in one of two modes:
// - Normal (debugFile == ""): human-readable text, INFO and above on screen.
// - Debug (debugFile != ""): same screen output, plus a full JSON trace of
// DEBUG and above written to debugFile for post-run investigation.
//
// When stderr is not a terminal (piped or redirected), NewCLI behaves like
// New: JSON at the given level to stderr; debugFile is ignored.
//
// Passing a level above "info" when running in a terminal is unusual —
// NewCLI will log a warning because interactive mode always shows INFO and above.
//
// Valid levels: debug, info, warn, error.
func NewCLI(level, debugFile string) result.Expect[*Logger] {
lvl := parseLevel(level)
if lvl.Err() != nil {
return result.Errw[*Logger](lvl.Err(), "parse log level")
}
return &Logger{slog.New(h)}
if !isTerminal(os.Stderr) {
h := slog.NewJSONHandler(os.Stderr, &slog.HandlerOptions{Level: lvl.Value()})
return result.Ok(&Logger{slog.New(h)})
}
screen := newHumanHandler(os.Stderr, slog.LevelInfo)
var h slog.Handler = screen
if debugFile != "" {
f, err := os.Create(debugFile)
if err != nil {
return result.Errw[*Logger](err, "create debug log")
}
dump := slog.NewJSONHandler(f, &slog.HandlerOptions{Level: slog.LevelDebug})
h = multiHandler{screen, dump}
}
log := &Logger{slog.New(h)}
if lvl.Value() > slog.LevelInfo {
log.Warn("log level set above INFO — interactive mode always shows INFO and above",
"requested", level)
}
return result.Ok(log)
}
// IsInteractive reports whether stderr is attached to a terminal.
// Use this when the application itself needs to adjust behavior based on
// whether a human operator is watching (e.g. progress bars, prompts).
func IsInteractive() bool {
return isTerminal(os.Stderr)
}
// NewWriter creates a JSON logger writing to w. Intended for tests that need to
@ -67,9 +120,8 @@ func NewWriter(w io.Writer, level string) result.Expect[*Logger] {
return result.Errw[*Logger](lvl.Err(), "parse log level")
}
handler := slog.NewJSONHandler(w, &slog.HandlerOptions{Level: lvl.Value()})
return result.Ok(&Logger{slog.New(handler)})
h := slog.NewJSONHandler(w, &slog.HandlerOptions{Level: lvl.Value()})
return result.Ok(&Logger{slog.New(h)})
}
// NewNop returns a no-op logger. Useful in tests that don't care about logs.
@ -90,7 +142,6 @@ func (l *Logger) WithFields(fields map[string]any) *Logger {
for k, v := range fields {
args = append(args, k, v)
}
return &Logger{l.Logger.With(args...)}
}
@ -101,6 +152,5 @@ func parseLevel(level string) result.Expect[slog.Level] {
if err := lvl.UnmarshalText([]byte(level)); err != nil {
return result.Errw[slog.Level](err, "unknown level (use debug|info|warn|error)")
}
return result.Ok(lvl)
}

View File

@ -7,6 +7,31 @@ import (
"gitea.djmil.dev/go/template/pkg/testutil"
)
func TestNewCLI(t *testing.T) {
tests := []struct {
level string
wantErr bool
}{
{level: "debug"},
{level: "info"},
{level: "warn"},
{level: "error"},
{level: "invalid", wantErr: true},
{level: "", wantErr: true},
}
for _, tc := range tests {
t.Run(tc.level, func(t *testing.T) {
// In tests stderr is not a terminal — NewCLI uses JSON path.
r := logger.NewCLI(tc.level, "")
if tc.wantErr {
testutil.ResultErr(t, r)
return
}
testutil.ResultOkNotNil(t, r)
})
}
}
func TestNew(t *testing.T) {
tests := []struct {
level string