felhom-agent/internal/log/log.go

// Package log builds the agent's slog logger. Kept tiny on purpose; the agent is
// a host service, so logs go to stderr (journald-friendly). Secrets must never be
// passed to the logger — config is logged only via Config.Redacted (see config).
//
// Observability pass (v0.83.0): New now fans out to TWO handlers — stderr at the
// configured level (journald behavior unchanged) and an in-memory debug Ring fixed
// at LevelDebug. The ring is the remote-diagnostics capture layer: DEBUG detail
// exists for GET /debug/logs and the heartbeat log-pull WITHOUT a config flip.
package log

import (
	"context"
	"io"
	"log/slog"
	"os"
	"strings"
	"sync"
	"time"
)

// DefaultRingSize is the debug ring's entry capacity (~1000 lines ≈ a few hours of
// normal operation; the heartbeat tail is additionally byte-capped by its caller).
const DefaultRingSize = 1000

// New returns a text slog.Logger at the given level ("debug"|"info"|"warn"|
// "error"; unknown falls back to info) writing to stderr, plus the debug Ring
// that captures EVERY record at LevelDebug regardless of the stderr level.
func New(level string) (*slog.Logger, *Ring) {
	return NewWithWriter(os.Stderr, level, DefaultRingSize)
}

// NewWithWriter is the injectable constructor (tests capture the stderr stream).
func NewWithWriter(w io.Writer, level string, ringSize int) (*slog.Logger, *Ring) {
	lvl := ParseLevel(level)
	ring := NewRing(ringSize)
	stderrH := slog.NewTextHandler(w, &slog.HandlerOptions{Level: lvl})
	// The ring handler is FIXED at LevelDebug — the capture layer must hold flow
	// detail even when the emit level is info (the motivating incident: an info box
	// showed nothing about a refused NAS verify because the detail never existed).
	ringH := slog.NewTextHandler(ring, &slog.HandlerOptions{Level: slog.LevelDebug})
	return slog.New(fanout{stderrH, ringH}), ring
}

// ParseLevel maps a config level string to a slog.Level (unknown → info).
func ParseLevel(level string) slog.Level {
	switch strings.ToLower(level) {
	case "debug":
		return slog.LevelDebug
	case "warn", "warning":
		return slog.LevelWarn
	case "error":
		return slog.LevelError
	default:
		return slog.LevelInfo
	}
}

// fanout dispatches one record to every handler whose level admits it. Each
// handler keeps its own level, so the ring can capture DEBUG while stderr stays
// at the configured emit level.
type fanout []slog.Handler

func (f fanout) Enabled(ctx context.Context, lvl slog.Level) bool {
	for _, h := range f {
		if h.Enabled(ctx, lvl) {
			return true
		}
	}
	return false
}

func (f fanout) Handle(ctx context.Context, r slog.Record) error {
	var firstErr error
	for _, h := range f {
		if !h.Enabled(ctx, r.Level) {
			continue
		}
		if err := h.Handle(ctx, r.Clone()); err != nil && firstErr == nil {
			firstErr = err
		}
	}
	return firstErr
}

func (f fanout) WithAttrs(attrs []slog.Attr) slog.Handler {
	out := make(fanout, len(f))
	for i, h := range f {
		out[i] = h.WithAttrs(attrs)
	}
	return out
}

func (f fanout) WithGroup(name string) slog.Handler {
	out := make(fanout, len(f))
	for i, h := range f {
		out[i] = h.WithGroup(name)
	}
	return out
}

// Entry is one captured log record, parsed from the slog text line (the port of
// the controller's web.LogBuffer entry, adapted to slog's text format).
type Entry struct {
	Time    time.Time `json:"timestamp"`
	Level   string    `json:"level"`   // DEBUG | INFO | WARN | ERROR
	Message string    `json:"message"` // msg=… plus attrs, verbatim from the text handler
}

// Ring is a thread-safe fixed-size ring of Entries. It implements io.Writer so a
// slog.TextHandler can feed it (one Write per record — TextHandler writes each
// record as a single line).
type Ring struct {
	mu      sync.RWMutex
	entries []Entry
	pos     int
	full    bool
}

// NewRing creates a ring keeping the last size entries (size ≤ 0 → DefaultRingSize).
func NewRing(size int) *Ring {
	if size <= 0 {
		size = DefaultRingSize
	}
	return &Ring{entries: make([]Entry, size)}
}

// Write parses one slog text line ("time=… level=… msg=… k=v …") into an Entry.
func (r *Ring) Write(p []byte) (int, error) {
	line := strings.TrimRight(string(p), "\r\n")
	if line == "" {
		return len(p), nil
	}
	e := parseSlogLine(line)
	r.mu.Lock()
	r.entries[r.pos] = e
	r.pos = (r.pos + 1) % len(r.entries)
	if r.pos == 0 && !r.full {
		r.full = true
	}
	r.mu.Unlock()
	return len(p), nil
}

// Entries returns up to limit entries in chronological order (newest kept when
// truncating; limit ≤ 0 or > cap → everything held) plus the total held count.
func (r *Ring) Entries(limit int) ([]Entry, int) {
	r.mu.RLock()
	defer r.mu.RUnlock()
	total := r.pos
	start := 0
	if r.full {
		total = len(r.entries)
		start = r.pos
	}
	out := make([]Entry, 0, total)
	for i := 0; i < total; i++ {
		out = append(out, r.entries[(start+i)%len(r.entries)])
	}
	if limit > 0 && len(out) > limit {
		out = out[len(out)-limit:]
	}
	return out, total
}

// Lines renders the held entries as plain text lines (chronological), dropping
// from the HEAD (oldest) to honor maxBytes so the newest lines survive — the
// heartbeat log-tail budget (maxBytes ≤ 0 → no byte cap).
func (r *Ring) Lines(maxBytes int) []string {
	entries, _ := r.Entries(0)
	lines := make([]string, len(entries))
	for i, e := range entries {
		lines[i] = e.Time.Format(time.RFC3339) + " [" + e.Level + "] " + e.Message
	}
	if maxBytes <= 0 {
		return lines
	}
	total := 0
	start := len(lines)
	for i := len(lines) - 1; i >= 0; i-- {
		total += len(lines[i]) + 1 // +1 for the newline it represents
		if total > maxBytes {
			break
		}
		start = i
	}
	return lines[start:]
}

// parseSlogLine splits a TextHandler line into time / level / the rest. Attrs and
// the quoted msg stay verbatim in Message — honest, and immune to quoting edge
// cases the viewer doesn't need parsed.
func parseSlogLine(line string) Entry {
	e := Entry{Level: "INFO", Message: line, Time: time.Now()}
	rest := line
	if v, r2, ok := cutField(rest, "time="); ok {
		if t, err := time.Parse(time.RFC3339Nano, v); err == nil {
			e.Time = t
		}
		rest = r2
	}
	if v, r2, ok := cutField(rest, "level="); ok {
		switch v {
		case "DEBUG", "INFO", "WARN", "ERROR":
			e.Level = v
		}
		rest = r2
	}
	e.Message = rest
	return e
}

// cutField extracts a leading `key=value ` field (unquoted — slog never quotes
// its own time/level values) and returns the value + the remainder.
func cutField(s, key string) (val, rest string, ok bool) {
	if !strings.HasPrefix(s, key) {
		return "", s, false
	}
	s = s[len(key):]
	if i := strings.IndexByte(s, ' '); i >= 0 {
		return s[:i], s[i+1:], true
	}
	return s, "", true
}