debug.go

// Package debug provides a tiny namespaced logger with colorized output,
// inspired by the npm debug package. Output format, color, and which
// namespaces are active are controlled by environment variables, making it
// safe for production:
//
//   NO_COLOR=1           disable ANSI color codes (also auto-disabled when
//                        stdout/stderr is not a TTY)
//   DEBUG_FORMAT=json    emit newline-delimited JSON instead of text
//                        (compatible with Datadog and other log shippers)
//   GO_DEBUG=app:*,db    enable only loggers whose namespace matches one
//                        of the listed patterns. Use `-` prefix to skip:
//                        `GO_DEBUG=*,-server:*` enables everything except
//                        loggers under `server:`. Unset = log everything.
package debug

import (
	"encoding/json"
	"fmt"
	"hash/fnv"
	"io"
	"os"
	"reflect"
	"strconv"
	"strings"
	"sync"
	"time"
	"unicode"
)

// Format selects the on-the-wire encoding for log lines.
type Format int

const (
	FormatText Format = iota
	FormatJSON
)

// Level identifies the severity of a single log entry.
type Level string

const (
	LevelDebug Level = "debug"
	LevelInfo  Level = "info"
	LevelWarn  Level = "warn"
	LevelError Level = "error"
	LevelFatal Level = "fatal"
)

// osExit is the function called by Fatal / Fatalf. Overridable in tests.
var osExit = os.Exit

// Options configures a Logger. Zero value is valid: stdout/stderr, text
// format, color auto-detected from env + TTY.
type Options struct {
	Out    io.Writer
	Err    io.Writer
	Format Format
	// Color forces color on/off. If nil, behavior derives from NO_COLOR
	// and whether the target writer is a terminal.
	Color *bool
	// Filter overrides the GO_DEBUG namespace filter. The empty string
	// means "use the GO_DEBUG env var"; pass a non-empty pattern (or the
	// literal string "*") to bypass the environment entirely.
	Filter string
	// Now overrides the clock. Used in tests.
	Now func() time.Time
}

// Logger is a namespaced debug logger. Methods are safe for concurrent use.
type Logger struct {
	namespace string
	format    Format
	out       io.Writer
	err       io.Writer
	colorOut  bool
	colorErr  bool
	enabled   bool
	startSeq  string // ANSI start (empty if color disabled)
	endSeq    string // ANSI end   (empty if color disabled)
	now       func() time.Time

	mu   sync.Mutex
	last time.Time
}

// New creates a Logger with default options derived from the environment.
func New(namespace string) *Logger {
	return NewWith(namespace, Options{})
}

// NewWith creates a Logger with explicit options. Any zero field falls back
// to the environment-derived default.
func NewWith(namespace string, opts Options) *Logger {
	out := opts.Out
	if out == nil {
		out = os.Stdout
	}
	errW := opts.Err
	if errW == nil {
		errW = os.Stderr
	}
	now := opts.Now
	if now == nil {
		now = time.Now
	}

	format := opts.Format
	if opts.Out == nil && opts.Err == nil {
		// Only honor env-driven format when caller did not override writers.
		if envFormat() == FormatJSON {
			format = FormatJSON
		}
	}

	colorOut := decideColor(opts.Color, out)
	colorErr := decideColor(opts.Color, errW)
	// JSON output keeps ANSI only when the writer is a terminal. The TTY
	// heuristic inside decideColor already covers piped output, so a JSON
	// stream destined for a log shipper never carries escape codes.

	code := colorCode(namespace)
	start := "[38;5;" + strconv.Itoa(code) + "m"
	end := ""

	filter := opts.Filter
	if filter == "" {
		filter = os.Getenv("GO_DEBUG")
	}

	return &Logger{
		namespace: namespace,
		format:    format,
		out:       out,
		err:       errW,
		colorOut:  colorOut,
		colorErr:  colorErr,
		enabled:   namespaceEnabled(namespace, filter),
		startSeq:  start,
		endSeq:    end,
		now:       now,
		last:      now(),
	}
}

// Enabled reports whether log calls on this Logger will produce output, based
// on the namespace filter resolved at construction time. Useful for guarding
// expensive argument assembly:
//
//	if l.Enabled() {
//	    l.Logf("dump=%v", veryExpensiveSnapshot())
//	}
func (l *Logger) Enabled() bool { return l.enabled }

// Debug logs at debug level on stdout.
func (l *Logger) Debug(messages ...string) { l.emit(LevelDebug, messages) }

// Info logs at info level on stdout.
func (l *Logger) Info(messages ...string) { l.emit(LevelInfo, messages) }

// Warn logs at warn level on stderr.
func (l *Logger) Warn(messages ...string) { l.emit(LevelWarn, messages) }

// Error logs at error level on stderr.
func (l *Logger) Error(messages ...string) { l.emit(LevelError, messages) }

// Fatal logs at fatal level on stderr and then terminates the process with
// exit code 1. The exit happens unconditionally — silencing the namespace
// via GO_DEBUG suppresses the message but never the exit, so log routing
// cannot accidentally swallow a process-death signal.
func (l *Logger) Fatal(messages ...string) {
	l.emit(LevelFatal, messages)
	osExit(1)
}

// Debugf / Infof / Warnf / Errorf / Fatalf are printf-style counterparts.
// Complex args (struct/map/slice/array) are rendered as JSON with syntax
// highlighting in color mode; in JSON output they also become structured
// `params` on the entry.

func (l *Logger) Debugf(format string, args ...any) { l.emitf(LevelDebug, format, args) }
func (l *Logger) Infof(format string, args ...any)  { l.emitf(LevelInfo, format, args) }
func (l *Logger) Warnf(format string, args ...any)  { l.emitf(LevelWarn, format, args) }
func (l *Logger) Errorf(format string, args ...any) { l.emitf(LevelError, format, args) }
func (l *Logger) Fatalf(format string, args ...any) {
	l.emitf(LevelFatal, format, args)
	osExit(1)
}

// emit handles plain message logging. Picks the stream + color flag based
// on level, short-circuits when the namespace is filtered out.
func (l *Logger) emit(level Level, messages []string) {
	if !l.enabled {
		return
	}
	w, useColor := l.streamFor(level)
	l.write(w, useColor, level, strings.Join(messages, " "), nil)
}

// emitf is the printf counterpart of emit.
func (l *Logger) emitf(level Level, format string, args []any) {
	if !l.enabled {
		return
	}
	w, useColor := l.streamFor(level)
	msg := l.formatMessage(format, args, useColor)
	l.write(w, useColor, level, msg, args)
}

// streamFor routes a level to its writer + color flag. Debug and Info go
// to stdout; Warn, Error, Fatal go to stderr.
func (l *Logger) streamFor(level Level) (io.Writer, bool) {
	switch level {
	case LevelDebug, LevelInfo:
		return l.out, l.colorOut
	default:
		return l.err, l.colorErr
	}
}

func (l *Logger) write(w io.Writer, useColor bool, level Level, message string, params []any) {
	now := l.now()

	l.mu.Lock()
	diff := now.Sub(l.last)
	l.last = now
	if l.format == FormatJSON {
		buf := encodeJSON(l.namespace, level, now, diff, message, params)
		if useColor {
			buf = []byte(highlightJSON(buf))
		}
		_, _ = w.Write(buf)
	} else {
		buf := encodeText(l.namespace, level, now, diff, message, useColor, l.startSeq, l.endSeq)
		_, _ = w.Write(buf)
	}
	l.mu.Unlock()
}

// formatMessage applies Sprintf to format, but pre-renders each arg so that
// complex values become syntax-highlighted JSON in color mode.
func (l *Logger) formatMessage(format string, args []any, useColor bool) string {
	if l.format == FormatJSON {
		// In JSON mode the params travel in their own field. Keep the
		// message free of ANSI and rendered with plain fmt formatting.
		return fmt.Sprintf(format, args...)
	}
	if len(args) == 0 {
		return format
	}
	rendered := make([]any, len(args))
	for i, a := range args {
		rendered[i] = renderArg(a, useColor)
	}
	return fmt.Sprintf(format, rendered...)
}

const textTimeFormat = "2006-01-02 15:04:05.000"

func encodeText(ns string, level Level, now time.Time, diff time.Duration, message string, useColor bool, start, end string) []byte {
	var b strings.Builder
	b.Grow(64 + len(ns) + len(message))

	if useColor {
		b.WriteString(start)
	}
	b.WriteString(ns)
	if level != LevelInfo {
		b.WriteByte(':')
		b.WriteString(string(level))
	}
	b.WriteString(" [")
	b.WriteString(now.Format(textTimeFormat))
	b.WriteByte(']')
	if useColor {
		b.WriteString(end)
	}
	b.WriteByte(' ')
	b.WriteString(message)
	if useColor {
		b.WriteString(start)
	}
	b.WriteString(" +")
	b.WriteString(strconv.FormatInt(diff.Milliseconds(), 10))
	b.WriteString("ms")
	if useColor {
		b.WriteString(end)
	}
	b.WriteByte('\n')
	return []byte(b.String())
}

type jsonEntry struct {
	Timestamp string `json:"timestamp"`
	Namespace string `json:"namespace"`
	Level     Level  `json:"level"`
	Message   string `json:"message"`
	DiffMS    int64  `json:"diff_ms"`
	Params    []any  `json:"params,omitempty"`
}

func encodeJSON(ns string, level Level, now time.Time, diff time.Duration, message string, params []any) []byte {
	entry := jsonEntry{
		Timestamp: now.UTC().Format(time.RFC3339Nano),
		Namespace: ns,
		Level:     level,
		Message:   message,
		DiffMS:    diff.Milliseconds(),
		Params:    params,
	}
	buf, err := json.Marshal(entry)
	if err != nil {
		// Some param may not be JSON-encodable. Fall back to a rendered
		// string representation so the entry still ships.
		entry.Params = nil
		entry.Message = message + " [unencodable params: " + err.Error() + "]"
		buf, _ = json.Marshal(entry)
	}
	return append(buf, '\n')
}

// renderArg returns the value used as a printf substitution. Complex kinds
// (struct/map/slice/array, including pointers to them) are encoded as JSON
// and, if color is on, syntax-highlighted. Scalars are passed through as
// fmt formats them.
func renderArg(v any, useColor bool) any {
	if v == nil {
		return v
	}
	rv := reflect.ValueOf(v)
	for rv.Kind() == reflect.Pointer || rv.Kind() == reflect.Interface {
		if rv.IsNil() {
			return v
		}
		rv = rv.Elem()
	}
	switch rv.Kind() {
	case reflect.Struct, reflect.Map, reflect.Slice, reflect.Array:
		buf, err := json.Marshal(v)
		if err != nil {
			return v
		}
		if useColor {
			return highlightJSON(buf)
		}
		return string(buf)
	default:
		return v
	}
}

// ANSI color codes used by highlightJSON. Mid-brightness, readable on both
// dark and light terminals.
const (
	ansiKey   = "" // cyan
	ansiStr   = "" // green
	ansiNum   = "" // yellow
	ansiBool  = "" // magenta
	ansiReset = ""
	ansiPunct = "" // dim gray for {},[]:
)

// highlightJSON walks raw JSON bytes (as produced by encoding/json, so it is
// well-formed) and emits the same bytes wrapped in ANSI sequences. It does
// not validate, only colorize.
func highlightJSON(src []byte) string {
	var b strings.Builder
	b.Grow(len(src) * 2)
	i := 0
	for i < len(src) {
		c := src[i]
		switch {
		case c == '"':
			end := scanJSONString(src, i)
			tok := src[i:end]
			// Key if next non-whitespace byte is ':'.
			j := end
			for j < len(src) && unicode.IsSpace(rune(src[j])) {
				j++
			}
			if j < len(src) && src[j] == ':' {
				b.WriteString(ansiKey)
			} else {
				b.WriteString(ansiStr)
			}
			b.Write(tok)
			b.WriteString(ansiReset)
			i = end
		case c == 't' || c == 'f' || c == 'n':
			end := i
			for end < len(src) && isLetter(src[end]) {
				end++
			}
			b.WriteString(ansiBool)
			b.Write(src[i:end])
			b.WriteString(ansiReset)
			i = end
		case c == '-' || (c >= '0' && c <= '9'):
			end := i
			for end < len(src) && isNumByte(src[end]) {
				end++
			}
			b.WriteString(ansiNum)
			b.Write(src[i:end])
			b.WriteString(ansiReset)
			i = end
		case c == '{' || c == '}' || c == '[' || c == ']' || c == ',' || c == ':':
			b.WriteString(ansiPunct)
			b.WriteByte(c)
			b.WriteString(ansiReset)
			i++
		default:
			b.WriteByte(c)
			i++
		}
	}
	return b.String()
}

func scanJSONString(src []byte, start int) int {
	// src[start] == '"'. Returns index after closing quote.
	i := start + 1
	for i < len(src) {
		switch src[i] {
		case '\\':
			i += 2
		case '"':
			return i + 1
		default:
			i++
		}
	}
	return len(src)
}

func isLetter(c byte) bool { return (c >= 'a' && c <= 'z') || (c >= 'A' && c <= 'Z') }

func isNumByte(c byte) bool {
	return (c >= '0' && c <= '9') || c == '.' || c == '-' || c == '+' || c == 'e' || c == 'E'
}

// colorCode derives an xterm-256 color in the visible mid-range (16..231),
// skipping the dark/basic block and the grayscale tail. FNV-1a 32-bit gives
// well-distributed output across the full byte space of the namespace.
func colorCode(s string) int {
	h := fnv.New32a()
	_, _ = h.Write([]byte(s))
	return int(h.Sum32()%216) + 16
}

func envFormat() Format {
	switch strings.ToLower(os.Getenv("DEBUG_FORMAT")) {
	case "json":
		return FormatJSON
	default:
		return FormatText
	}
}

// decideColor resolves the color setting. Order: explicit override, then
// NO_COLOR env (any non-empty value disables), then TTY detection on writer.
func decideColor(override *bool, w io.Writer) bool {
	if override != nil {
		return *override
	}
	if os.Getenv("NO_COLOR") != "" {
		return false
	}
	return isTerminal(w)
}

func isTerminal(w io.Writer) bool {
	f, ok := w.(*os.File)
	if !ok {
		return false
	}
	info, err := f.Stat()
	if err != nil {
		return false
	}
	// Character device = terminal. Regular files / pipes are not.
	return info.Mode()&os.ModeCharDevice != 0
}

// namespaceEnabled implements the npm-debug-style filter language used by
// GO_DEBUG. Patterns are separated by commas or whitespace. A pattern with
// a leading `-` is a skip; everything else is an enable. `*` is a wildcard
// matching any sequence of characters, including `:` separators.
//
// Rules:
//   - empty filter   => enabled (godebug defaults to permissive)
//   - any skip match => disabled (skips win over enables)
//   - any enable match => enabled
//   - otherwise => disabled
func namespaceEnabled(ns, filter string) bool {
	if filter == "" {
		return true
	}
	var enables, skips []string
	for _, p := range splitFilter(filter) {
		if strings.HasPrefix(p, "-") {
			skips = append(skips, p[1:])
		} else {
			enables = append(enables, p)
		}
	}
	for _, p := range skips {
		if globMatch(p, ns) {
			return false
		}
	}
	if len(enables) == 0 {
		// Only skips were specified; treat as "everything except skips".
		return true
	}
	for _, p := range enables {
		if globMatch(p, ns) {
			return true
		}
	}
	return false
}

func splitFilter(s string) []string {
	out := make([]string, 0, 4)
	start := -1
	for i := 0; i <= len(s); i++ {
		atSep := i == len(s) || s[i] == ',' || s[i] == ' ' || s[i] == '\t'
		if atSep {
			if start >= 0 {
				out = append(out, s[start:i])
				start = -1
			}
		} else if start < 0 {
			start = i
		}
	}
	return out
}

// globMatch performs a wildcard match where `*` matches any (possibly empty)
// run of bytes. No other metacharacters. Iterative backtracking, no regex.
func globMatch(pat, s string) bool {
	pi, si := 0, 0
	star, sBack := -1, 0
	for si < len(s) {
		switch {
		case pi < len(pat) && pat[pi] == '*':
			star = pi
			sBack = si
			pi++
		case pi < len(pat) && pat[pi] == s[si]:
			pi++
			si++
		case star != -1:
			pi = star + 1
			sBack++
			si = sBack
		default:
			return false
		}
	}
	for pi < len(pat) && pat[pi] == '*' {
		pi++
	}
	return pi == len(pat)
}