feat(logging): configure levels and structured runtime output

README.md

@@ -433,3 +433,17 @@ Beacon.
 
 Beacon stands on the shoulders of giants. See [SHOULDERS.md](SHOULDERS.md) for
 the full list of open source projects that make this possible.
+
+## Application logging
+
+Beacon writes application logs to stderr. Configure the minimum level and output format in `config.yaml`:
+
+```yaml
+log:
+  level: info   # debug, info, warn, error
+  format: text  # text or json
+```
+
+`LOG_LEVEL` and `LOG_FORMAT` override file settings; empty settings use `info` and `text`. Invalid values prevent startup. Configuration-loading failures can use the bootstrap text logger before file settings are available; failures after initialization retain error severity at every supported level.
+
+Records include a component field. Ingest workers also include their broker name, and HTTP completion records include the validated client address, route, status and duration. Query strings and protocol hello payloads are excluded. Expected ingest skips and routine WebSocket lifecycle details are debug-level. Changing the application's format does not change Caddy/Apache access logs or their fail2ban configuration. Collect/rotate stderr through Docker or systemd.

cmd/beacon/main.go

@@ -7,7 +7,7 @@ import (
 	"context"
 	"encoding/hex"
 	"fmt"
-	"log"
+	"log/slog"
 	"net/http"
 	"os"
 	"os/signal"
@@ -26,6 +26,7 @@ import (
 	"github.com/MeshCore-Beacon/beacon-server/internal/iatadb"
 	"github.com/MeshCore-Beacon/beacon-server/internal/ingest"
 	"github.com/MeshCore-Beacon/beacon-server/internal/keystore"
+	"github.com/MeshCore-Beacon/beacon-server/internal/logging"
 	"github.com/MeshCore-Beacon/beacon-server/internal/presence"
 	"github.com/MeshCore-Beacon/beacon-server/internal/scopestore"
 
@@ -72,7 +73,6 @@ var version = "dev"
 // @tag.name			Stats
 // @tag.description	Network statistics and time series
 func main() {
-	log.Printf("beacon version %s", version)
 	_ = godotenv.Load()
 	addr := os.Getenv("LISTEN_ADDR")
 	if addr == "" {
@@ -86,15 +86,23 @@ func main() {
 
 	cfg, err := config.Load(configPath)
 	if err != nil {
-		log.Fatalf("failed to load config: %v", err)
+		slog.Error("failed to load config", "component", "startup", "error", err)
+		os.Exit(1)
 	}
+	logger, err := logging.New(os.Stderr, cfg.Log)
+	if err != nil {
+		slog.Error("invalid logging configuration", "component", "startup", "error", err)
+		os.Exit(1)
+	}
+	slog.SetDefault(logger)
+	slog.Info("beacon starting", "component", "startup", "version", version)
 	if len(cfg.Server.TrustedProxies) == 0 {
-		log.Print("warning: server.trusted_proxies is empty; client IP headers are ignored and proxied clients share a WebSocket connection limit")
+		slog.Warn("warning: server.trusted_proxies is empty; client IP headers are ignored and proxied clients share a WebSocket connection limit", "component", "startup")
 	}
 
 	resolved := config.Resolve(cfg)
 
-	log.Printf("config: loaded — %s", resolved)
+	slog.Info(fmt.Sprintf("config: loaded — %s", resolved), "component", "startup")
 
 	// ── Hub ──────────────────────────────────────────────────────────────────
 	h := hub.New()
@@ -106,12 +114,15 @@ func main() {
 
 	pool, err := pgxpool.New(ctx, getEnv("POSTGRES_DSN"))
 	if err != nil {
-		log.Fatalf("failed to connect to postgres at %s: %v", os.Getenv("POSTGRES_DSN_HOST"), err)
+		// Parse errors can embed the complete DSN, including its password.
+		slog.Error("invalid PostgreSQL connection configuration; check POSTGRES_DSN", "component", "startup")
+		os.Exit(1)
 	}
 	defer pool.Close()
 
 	if err := db.RunMigrations(ctx, pool); err != nil {
-		log.Fatalf("migrations failed: %v", err)
+		slog.Error("migrations failed", "component", "startup", "error", err)
+		os.Exit(1)
 	}
 
 	store := db.New(pool, resolved.ClockDriftThreshold, resolved.NodeStaleThreshold)
@@ -138,29 +149,30 @@ func main() {
 			}(),
 		)
 		if err := redisClient.Ping(ctx); err != nil {
-			log.Printf("warning: redis unavailable at %s, caching disabled: %v", redisAddr, err)
+			slog.Warn(fmt.Sprintf("warning: redis unavailable at %s, caching disabled", redisAddr), "component", "startup", "error", err)
 		} else {
 			ttls := cache.ResolveTTLs(cfg.Cache)
 			reader = cache.NewCachedReader(store, redisClient, ttls)
 			defer redisClient.Close()
-			log.Printf("cache: Redis connected at %s (stats=%s reference=%s nodes=%s observers=%s)",
-				redisAddr, ttls.Stats, ttls.Reference, ttls.Nodes, ttls.Observers)
+			slog.Info(fmt.Sprintf("cache: Redis connected at %s (stats=%s reference=%s nodes=%s observers=%s)", redisAddr, ttls.Stats, ttls.Reference, ttls.Nodes, ttls.Observers), "component", "startup")
 		}
 	}
 
 	// ── Seed config data ─────────────────────────────────────────────────────
 	if err := config.Seed(ctx, cfg, store); err != nil {
-		log.Fatalf("failed to seed config: %v", err)
+		slog.Error("failed to seed config", "component", "startup", "error", err)
+		os.Exit(1)
 	}
 
 	// ── Build transport scope keystore ───────────────────────────────────────
 	scopes := scopestore.New()
 	scopeEntries, err := store.GetTransportScopes(ctx)
 	if err != nil {
-		log.Fatalf("failed to load transport scopes: %v", err)
+		slog.Error("failed to load transport scopes", "component", "startup", "error", err)
+		os.Exit(1)
 	}
 	scopes.Load(scopeEntries)
-	log.Printf("loaded %d transport scopes", len(scopeEntries))
+	slog.Info(fmt.Sprintf("loaded %d transport scopes", len(scopeEntries)), "component", "startup")
 
 	// ── Build channel keystore ──────────────────────────────────────────────
 	entries := make(map[string][]keystore.Entry)
@@ -177,15 +189,15 @@ func main() {
 		}
 		if !keystore.EntryExists(entries[hashHex], entry) {
 			entries[hashHex] = append(entries[hashHex], entry)
-			log.Printf("config: loaded hashtag channel #%s (hash=%s)", tag, hashHex)
+			slog.Info(fmt.Sprintf("config: loaded hashtag channel #%s (hash=%s)", tag, hashHex), "component", "startup")
 		}
 	}
 
 	// Explicit keys: hash provided directly, key is hex-encoded
 	for hashHex, keyCfg := range cfg.ChannelKeys.Keys {
 		key, err := hex.DecodeString(keyCfg.Key)
 		if err != nil {
-			log.Printf("warning: invalid channel key for hash %s, skipping: %v", hashHex, err)
+			slog.Warn(fmt.Sprintf("warning: invalid channel key for hash %s, skipping", hashHex), "component", "startup", "error", err)
 			continue
 		}
 		entry := keystore.Entry{
@@ -195,7 +207,7 @@ func main() {
 		}
 		if !keystore.EntryExists(entries[hashHex], entry) {
 			entries[hashHex] = append(entries[hashHex], entry)
-			log.Printf("config: loaded explicit channel key for hash %s name=%q", hashHex, keyCfg.Name)
+			slog.Info(fmt.Sprintf("config: loaded explicit channel key for hash %s name=%q", hashHex, keyCfg.Name), "component", "startup")
 		}
 	}
 
@@ -207,18 +219,17 @@ func main() {
 	// built, so adding a channel key to the config surfaces its history on the next boot
 	// instead of leaving it stranded in the DB indefinitely.
 	if n, err := ingest.BackfillChannelMessages(ctx, store, keys); err != nil {
-		log.Printf("config: channel message backfill failed: %v", err)
+		slog.Error("config: channel message backfill failed", "component", "startup", "error", err)
 	} else if n > 0 {
-		log.Printf("config: backfilled %d previously-undecrypted channel message(s)", n)
+		slog.Info(fmt.Sprintf("config: backfilled %d previously-undecrypted channel message(s)", n), "component", "startup")
 	}
 
 	// ── Build geographic ingest filter ───────────────────────────────────────────────────────────
 	allowedIATAs := iatadb.BuildAllowedSet(cfg.Ingest.AllowCountries, cfg.Ingest.AllowContinents)
 	if allowedIATAs != nil {
-		log.Printf("config: ingest filter active — %d allowed IATAs (countries=%v continents=%v)",
-			len(allowedIATAs), cfg.Ingest.AllowCountries, cfg.Ingest.AllowContinents)
+		slog.Info(fmt.Sprintf("config: ingest filter active — %d allowed IATAs (countries=%v continents=%v)", len(allowedIATAs), cfg.Ingest.AllowCountries, cfg.Ingest.AllowContinents), "component", "startup")
 	} else {
-		log.Printf("config: ingest filter inactive — accepting all IATAs")
+		slog.Info("config: ingest filter inactive — accepting all IATAs", "component", "startup")
 	}
 
 	broker1 := ingest.New(
@@ -278,14 +289,16 @@ func main() {
 	r := router.New(h, reader, []*ingest.Worker{broker1, broker2}, resolved.MaxConnsPerIP, cfg.CORS, cfg.Server)
 
 	srv := &http.Server{
-		Addr:    addr,
-		Handler: r,
+		Addr:     addr,
+		Handler:  r,
+		ErrorLog: slog.NewLogLogger(slog.Default().With("component", "http").Handler(), slog.LevelError),
 	}
 
 	go func() {
-		fmt.Printf("Beacon listening on %s\n", addr)
+		slog.Info(fmt.Sprintf("Beacon listening on %s", addr), "component", "startup")
 		if err := srv.ListenAndServe(); err != nil && err != http.ErrServerClosed {
-			log.Fatalf("server error: %v", err)
+			slog.Error("server error", "component", "startup", "error", err)
+			os.Exit(1)
 		}
 	}()
 
@@ -294,12 +307,12 @@ func main() {
 	signal.Notify(quit, syscall.SIGINT, syscall.SIGTERM)
 	<-quit
 
-	log.Println("shutting down...")
+	slog.Info("shutting down...", "component", "startup")
 	cancel() // stops ingest workers
 	shutdownCtx, shutdownCancel := context.WithTimeout(context.Background(), 30*time.Second)
 	defer shutdownCancel()
 	if err := srv.Shutdown(shutdownCtx); err != nil {
-		log.Printf("server shutdown error: %v", err)
+		slog.Error("server shutdown error", "component", "startup", "error", err)
 	}
 	coalescer.Flush(shutdownCtx)
 }
@@ -310,7 +323,7 @@ func main() {
 func getEnv(key string) string {
 	v := os.Getenv(key)
 	if v == "" {
-		log.Printf("warning: %s is not set", key)
+		slog.Warn(fmt.Sprintf("warning: %s is not set", key), "component", "startup")
 	}
 	return v
 }

cmd/beacon/main_test.go

@@ -0,0 +1,60 @@
+// Copyright 2026 Beacon Contributors
+// SPDX-License-Identifier: AGPL-3.0-or-later
+
+package main
+
+import (
+	"bytes"
+	"encoding/json"
+	"os"
+	"os/exec"
+	"path/filepath"
+	"strings"
+	"testing"
+)
+
+func TestStartupLogging(t *testing.T) {
+	if os.Getenv("BEACON_TEST_LOG_STARTUP") == "1" {
+		main()
+		return
+	}
+	for _, level := range []string{"debug", "info", "warn", "error"} {
+		t.Run(level, func(t *testing.T) {
+			dir := t.TempDir()
+			path := filepath.Join(dir, "config.yaml")
+			if err := os.WriteFile(path, []byte("log: {level: debug, format: text}\n"), 0600); err != nil {
+				t.Fatal(err)
+			}
+			cmd := exec.Command(os.Args[0], "-test.run=^TestStartupLogging$")
+			cmd.Dir = dir
+			// Invalid port fails during parsing, before any database/network connection.
+			cmd.Env = append(os.Environ(), "BEACON_TEST_LOG_STARTUP=1", "CONFIG_PATH="+path, "LOG_LEVEL="+level, "LOG_FORMAT=json", "POSTGRES_DSN=postgres://test:do-not-log-this@localhost:invalid/beacon")
+			out, err := cmd.CombinedOutput()
+			if err == nil {
+				t.Fatal("startup unexpectedly succeeded")
+			}
+			if strings.Contains(string(out), "do-not-log-this") {
+				t.Fatal("DSN credential leaked")
+			}
+			foundError := false
+			for _, line := range bytes.Split(bytes.TrimSpace(out), []byte("\n")) {
+				var record map[string]any
+				if err := json.Unmarshal(line, &record); err != nil {
+					t.Fatalf("non-JSON startup output: %s", line)
+				}
+				if record["level"] == "ERROR" {
+					foundError = true
+				}
+				if level == "error" && record["level"] != "ERROR" {
+					t.Fatal("error threshold ignored")
+				}
+				if level == "warn" && record["level"] != "WARN" && record["level"] != "ERROR" {
+					t.Fatal("warn threshold ignored")
+				}
+			}
+			if !foundError {
+				t.Fatal("startup failure was silent")
+			}
+		})
+	}
+}

config.yaml.example

@@ -1,6 +1,11 @@
 # Beacon configuration file
 # Copy to config.yaml and adjust as needed.
 
+log:
+  # Environment LOG_LEVEL / LOG_FORMAT override these values.
+  level: info  # debug, info, warn, error
+  format: text # text or json
+
 server:
   # Only these direct proxy peers may set the client IP through X-Real-IP.
   # The proxy must overwrite that header, not pass through client input.

db/migrate.go

@@ -9,6 +9,7 @@ import (
 	"errors"
 	"fmt"
 	"io/fs"
+	"log/slog"
 	"regexp"
 	"sort"
 	"strings"
@@ -70,13 +71,13 @@ func applyMigration(ctx context.Context, db execQuerier, sql string) error {
 		return fmt.Errorf("%w (checking index %s: %v)", err, name, scanErr)
 	}
 	if valid {
-		fmt.Printf("index %s already built, recording migration\n", name)
+		slog.Info(fmt.Sprintf("index %s already built, recording migration", name), "component", "db")
 		return nil
 	}
 	if _, dropErr := db.Exec(ctx, "DROP INDEX CONCURRENTLY IF EXISTS "+ident); dropErr != nil {
 		return fmt.Errorf("dropping invalid index %s: %w", name, dropErr)
 	}
-	fmt.Printf("dropped invalid index %s, rebuilding\n", name)
+	slog.Warn(fmt.Sprintf("dropped invalid index %s, rebuilding", name), "component", "db")
 	_, err = db.Exec(ctx, sql)
 	return err
 }
@@ -119,7 +120,7 @@ func RunMigrations(ctx context.Context, pool *pgxpool.Pool) error {
 			); err != nil {
 				return fmt.Errorf("failed to bootstrap migrations: %w", err)
 			}
-			fmt.Println("bootstrapped existing schema as 001_initial_schema.sql")
+			slog.Info("bootstrapped existing schema as 001_initial_schema.sql", "component", "db")
 		}
 	}
 
@@ -166,7 +167,7 @@ func RunMigrations(ctx context.Context, pool *pgxpool.Pool) error {
 			return fmt.Errorf("failed to record migration %s: %w", entry.Name(), err)
 		}
 
-		fmt.Printf("applied migration: %s\n", entry.Name())
+		slog.Info(fmt.Sprintf("applied migration: %s", entry.Name()), "component", "db")
 	}
 
 	return nil

db/nodes.go

@@ -9,7 +9,7 @@ import (
 	"encoding/json"
 	"errors"
 	"fmt"
-	"log"
+	"log/slog"
 	"time"
 
 	sqlc "github.com/MeshCore-Beacon/beacon-server/db/sqlc"
@@ -132,7 +132,7 @@ func (s *Store) ListNodes(ctx context.Context, nodeType int16, iatas []string, s
 		}
 		if len(v.Iatas) > 0 {
 			if err := json.Unmarshal(v.Iatas, &node.IATAs); err != nil {
-				log.Printf("store: failed to unmarshal node iatas: %v", err)
+				slog.Error("store: failed to unmarshal node iatas", "component", "db", "error", err)
 				node.IATAs = []api.NodeIATA{}
 			}
 		}
@@ -184,13 +184,13 @@ func (s *Store) GetNode(ctx context.Context, nodeID uuid.UUID) (*api.Node, error
 	}
 	neighbors, err := s.GetNodeNeighbors(ctx, nodeID)
 	if err != nil {
-		log.Printf("store: GetNodeNeighbors failed for %s: %v", nodeID, err)
+		slog.Error(fmt.Sprintf("store: GetNodeNeighbors failed for %s", nodeID), "component", "db", "error", err)
 		neighbors = []api.NodeNeighbor{}
 	}
 	node.Neighbors = neighbors
 	if len(row.Iatas) > 0 {
 		if err := json.Unmarshal(row.Iatas, &node.IATAs); err != nil {
-			log.Printf("store: failed to unmarshal node iatas: %v", err)
+			slog.Error("store: failed to unmarshal node iatas", "component", "db", "error", err)
 			node.IATAs = []api.NodeIATA{}
 		}
 	}

db/observers.go

@@ -7,7 +7,7 @@ import (
 	"context"
 	"encoding/hex"
 	"fmt"
-	"log"
+	"log/slog"
 	"time"
 
 	sqlc "github.com/MeshCore-Beacon/beacon-server/db/sqlc"
@@ -122,7 +122,7 @@ func (s *Store) GetObserver(ctx context.Context, observerID uuid.UUID) (*api.Obs
 	}
 	scopes, err := s.GetObserverScopes(ctx, observerID)
 	if err != nil {
-		log.Printf("store: GetObserverScopes failed for %s: %v", observerID, err)
+		slog.Error(fmt.Sprintf("store: GetObserverScopes failed for %s", observerID), "component", "db", "error", err)
 		scopes = []string{}
 	}
 	observer.Scopes = scopes
@@ -357,7 +357,7 @@ func (s *Store) ListObserverAdverts(ctx context.Context, observerID uuid.UUID, c
 		Limit:      limit + 1, // fetch one extra to detect hasMore
 	})
 	if err != nil {
-		log.Printf("api: ListObserverAdverts failed: %v", err)
+		slog.Error("api: ListObserverAdverts failed", "component", "db", "error", err)
 		return api.Page[api.AdvertObservation]{}, err
 	}
 	hasMore := len(rows) > int(limit)