Files
zeekayandHanzo Dev 13404430a5 a frame that arrived is a trace, not news
The broker named three APIs as the chatty ones and announced every other
frame at Info. That is a guess about which calls a client repeats, and it
was wrong about the one that matters. Measured in production: Metadata was
824 of 1200 log lines, 69% of everything the process said. Eight minutes of
that rotates a pod's boot errors out of reach, which is how the last outage
came to need forensics instead of a read.

Every received frame is Debug now, so there is no list to keep correct as
APIs are added. Info stays for what an operator did not already know.

Two races were in the way of proving it, and `go test -race ./...` had never
passed here — seven at HEAD, before any of this.

Serve published the listener while Addr and Shutdown read it, with nothing
ordering the three. The bound port is now settled before the listener is
published, so a caller that can see one can see the other.

The level itself was a plain global read by every logging goroutine, and the
sink was chosen by a log.SetOutput on every single line — a process-global
written concurrently from every connection, which also left no way to read
back what was written. The level is atomic and the sink is chosen once.

TRACE was missing from the severity map and scored zero by absence; saying
it is cheaper than rediscovering why the order comes out right.

Co-authored-by: Hanzo Dev <[email protected]>
2026-08-13 19:14:27 -07:00

90 lines
2.2 KiB
Go

package logging
import (
"fmt"
"log"
"os"
"sync/atomic"
)
// logging levels
const (
TRACE = "TRACE"
DEBUG = "DEBUG"
INFO = "INFO"
WARN = "WARN"
ERROR = "ERROR"
)
// severity orders the levels. TRACE was missing from it, so it scored zero by
// the absence of an entry and the order came out right by accident; saying it
// is cheaper than rediscovering why it works.
var severity = map[string]int{
TRACE: 0,
DEBUG: 1,
INFO: 2,
WARN: 3,
ERROR: 4,
}
// threshold is the level at or above which a line is written. Every goroutine
// that logs reads it and SetLogLevel writes it, so it is held atomically — a
// host that changes level while connections are live raced every log call.
var threshold atomic.Value
// Lines go to stdout, chosen once. This used to be a log.SetOutput on EVERY
// line, so every connection goroutine wrote a process-global concurrently and
// no caller could read back what was written. Choosing it here says the same
// thing once, and a test can point the logger somewhere it can read.
func init() {
threshold.Store(INFO)
log.SetOutput(os.Stdout)
}
// SetLogLevel sets the log level for filtering logs
func SetLogLevel(logLevel string) {
threshold.Store(logLevel)
}
// LogLevel reports the level at or above which lines are written.
func LogLevel() string {
return threshold.Load().(string)
}
// Log writes a log message at a specified level, formatted with optional arguments
func Log(level, message string, a ...any) {
if severity[level] >= severity[LogLevel()] {
log.Printf("[%s] %s\n", level, fmt.Sprintf(message, a...))
}
}
// Trace logs a message at TRACE level
func Trace(message string, a ...any) {
Log(TRACE, message, a...)
}
// Debug logs a message at DEBUG level
func Debug(message string, a ...any) {
Log(DEBUG, message, a...)
}
// Info logs a message at INFO level
func Info(message string, a ...any) {
Log(INFO, message, a...)
}
// Warn logs a message at WARN level
func Warn(message string, a ...any) {
Log(WARN, message, a...)
}
// Error logs a message at ERROR level
func Error(message string, a ...any) {
Log(ERROR, message, a...)
}
// Panic exists with a panic
func Panic(message string, a ...any) {
panic(fmt.Sprintf(message, a...))
}