Feature: Security audit logging with admin web query page

Add a dedicated security audit trail to the Go server. Login attempts,
authorization denials, WebSocket lifecycle, remote screen and terminal
sessions, clipboard operations, device authentication and admin mutations
now emit stable JSON-line events (audit=true, event=<name>) to a separate
logs/audit.log, mirrored to server.log. The path is configurable through
YAMA_AUDIT_LOG and the separate file can be switched off. Records never
contain passcodes, password hashes, tokens or clipboard contents, and
untrusted string fields are stripped of control characters and truncated
so they cannot forge log lines.

Expose the trail to administrators through a query_audit WebSocket command
and an Audit Log page in the web UI. The page filters by time range, event
(exact or prefix), actor, IP, device id, keyword and warning level, pages
newest-first, and stays hidden unless the server advertises the auditLog
capability, so older C++ servers degrade cleanly. Each query scans at most
the newest 32 MB of the current file to bound latency, records itself as
admin.audit.query, and tolerates torn or non-audit lines.

Add unit tests for event emission and redaction, query filtering, paging,
malformed lines, missing or disabled audit files, and handler
authorization.

Co-Authored-By: deepseek-flash

server/go/logger/logger.go

@@ -1,10 +1,12 @@
 package logger
 
 import (
+	"fmt"
 	"io"
 	"os"
 	"path/filepath"
-	"time"
+	"strings"
+	"unicode/utf8"
 
 	"github.com/rs/zerolog"
 	"gopkg.in/natefinch/lumberjack.v2"
@@ -24,6 +26,13 @@ const (
 // Logger wraps zerolog.Logger
 type Logger struct {
 	zl zerolog.Logger
+	// audit is a second, file-only logger used for security audit records.
+	// It writes JSON lines to AuditFile so audit data is not buried in
+	// debug/operational output and can be retained independently.
+	audit        zerolog.Logger
+	auditEnabled bool
+	auditPath    string // "" when the separate audit file is disabled
+	closers      []io.Closer
 }
 
 // Config holds logger configuration
@@ -42,6 +51,19 @@ type Config struct {
 	MaxAge int
 	// Compress enables gzip compression for rotated files
 	Compress bool
+
+	// AuditFile is the dedicated security-audit log path ("" disables the
+	// separate audit file; audit records still go to the main log). Audit
+	// records are JSON lines with audit=true, event=<name>, and contextual
+	// fields such as actor/role/ip/device_id.
+	AuditFile string
+	// AuditMaxSize / AuditMaxBackups / AuditMaxAge tune audit rotation.
+	// Zero values pick 100 MB / 20 files / 90 days.
+	AuditMaxSize    int
+	AuditMaxBackups int
+	AuditMaxAge     int
+	// AuditCompress enables gzip compression for rotated audit files.
+	AuditCompress bool
 }
 
 // DefaultConfig returns default configuration
@@ -60,6 +82,7 @@ func DefaultConfig() Config {
 // New creates a new logger with config
 func New(cfg Config) *Logger {
 	var writers []io.Writer
+	var closers []io.Closer
 
 	// Console output with color
 	if cfg.Console {
@@ -87,6 +110,7 @@ func New(cfg Config) *Logger {
 			LocalTime:  true,
 		}
 		writers = append(writers, fileWriter)
+		closers = append(closers, fileWriter)
 	}
 
 	// Combine writers
@@ -106,14 +130,78 @@ func New(cfg Config) *Logger {
 		Timestamp().
 		Logger()
 
-	return &Logger{zl: zl}
+	l := &Logger{zl: zl, closers: closers}
+
+	if cfg.AuditFile != "" {
+		dir := filepath.Dir(cfg.AuditFile)
+		if dir != "" && dir != "." {
+			_ = os.MkdirAll(dir, 0755)
+		}
+		maxSize := cfg.AuditMaxSize
+		if maxSize <= 0 {
+			maxSize = 100
+		}
+		maxBackups := cfg.AuditMaxBackups
+		if maxBackups <= 0 {
+			maxBackups = 20
+		}
+		maxAge := cfg.AuditMaxAge
+		if maxAge <= 0 {
+			maxAge = 90
+		}
+		auditWriter := &lumberjack.Logger{
+			Filename:   cfg.AuditFile,
+			MaxSize:    maxSize,
+			MaxBackups: maxBackups,
+			MaxAge:     maxAge,
+			Compress:   cfg.AuditCompress,
+			LocalTime:  true,
+		}
+		l.audit = zerolog.New(auditWriter).
+			Level(zerolog.InfoLevel).
+			With().
+			Timestamp().
+			Logger()
+		l.auditEnabled = true
+		l.auditPath = cfg.AuditFile
+		l.closers = append(l.closers, auditWriter)
+	}
+
+	return l
+}
+
+// Close releases any file handles owned by the logger. Safe to call multiple
+// times. Loggers derived with WithPrefix share the base logger's files but do
+// not own them, so call Close on the logger returned by New.
+func (l *Logger) Close() error {
+	if l == nil {
+		return nil
+	}
+	for _, c := range l.closers {
+		_ = c.Close()
+	}
+	l.closers = nil
+	return nil
 }
 
 // WithPrefix returns a new logger with a prefix field
 func (l *Logger) WithPrefix(prefix string) *Logger {
-	return &Logger{
-		zl: l.zl.With().Str("module", prefix).Logger(),
+	n := &Logger{zl: l.zl.With().Str("module", prefix).Logger(), auditPath: l.auditPath}
+	if l.auditEnabled {
+		n.audit = l.audit.With().Str("module", prefix).Logger()
+		n.auditEnabled = true
 	}
+	return n
+}
+
+// AuditPath returns the path of the dedicated audit log file, or "" when the
+// separate audit file is disabled (audit records then only reach the main log).
+// Derived loggers (WithPrefix) report the same path.
+func (l *Logger) AuditPath() string {
+	if l == nil {
+		return ""
+	}
+	return l.auditPath
 }
 
 // Debug logs a debug message
@@ -151,21 +239,102 @@ func (l *Logger) GetLevel() Level {
 	return l.zl.GetLevel()
 }
 
-// ClientEvent logs client online/offline events
+// ClientEvent logs client online/offline events as audit records.
 func (l *Logger) ClientEvent(event string, clientID uint64, ip string, extra ...string) {
-	e := l.zl.Info().
-		Str("event", event).
-		Uint64("client_id", clientID).
-		Str("ip", ip).
-		Time("time", time.Now())
-
-	if len(extra) >= 2 {
-		for i := 0; i+1 < len(extra); i += 2 {
-			e = e.Str(extra[i], extra[i+1])
-		}
+	// clientID is the TCP connection id; the device's stable YAMA id arrives
+	// as the "clientID" extra and is normalized to device_id so every audit
+	// record uses the same field names (conn / device_id).
+	fields := map[string]any{
+		"conn": clientID,
+		"ip":   ip,
 	}
+	for i := 0; i+1 < len(extra); i += 2 {
+		key := extra[i]
+		if key == "clientID" {
+			key = "device_id"
+		}
+		fields[key] = extra[i+1]
+	}
+	l.Audit("device."+event, fields)
+}
 
-	e.Msg("")
+// Audit writes one security-audit record at info level.
+func (l *Logger) Audit(event string, fields map[string]any) {
+	l.AuditAt(LevelInfo, event, fields)
+}
+
+// AuditWarn writes one security-audit record at warn level. Use it for
+// rejected / failed security-relevant operations.
+func (l *Logger) AuditWarn(event string, fields map[string]any) {
+	l.AuditAt(LevelWarn, event, fields)
+}
+
+// AuditAt writes a security-audit record to the dedicated audit file (when
+// configured) and mirrors it to the main logger so operators tailing
+// server.log still see security events. event is a stable dotted name such
+// as "web.login.failure"; fields carry actor/role/ip/device_id/reason.
+//
+// Untrusted string values (usernames, User-Agent, Origin, device strings)
+// are sanitized: control characters are replaced so they cannot forge log
+// lines, and long values are truncated.
+func (l *Logger) AuditAt(level Level, event string, fields map[string]any) {
+	if l == nil {
+		return
+	}
+	clean := make(map[string]any, len(fields)+2)
+	for k, v := range fields {
+		clean[k] = sanitizeAuditValue(v)
+	}
+	clean["audit"] = true
+	clean["event"] = event
+
+	if l.auditEnabled {
+		l.audit.WithLevel(level).Fields(clean).Msg("audit")
+	}
+	l.zl.WithLevel(level).Fields(clean).Msg("audit")
+}
+
+// maxAuditValueLen bounds untrusted log values (runes). A 1 MB WebSocket
+// frame could otherwise be reflected verbatim into every audit line.
+const maxAuditValueLen = 512
+
+// maxAuditValueBytes is the pre-sanitization byte cap. It keeps a single
+// hostile value from allocating an unbounded rune slice before truncation.
+const maxAuditValueBytes = 4096
+
+func sanitizeAuditValue(v any) any {
+	switch x := v.(type) {
+	case string:
+		return sanitizeAuditString(x)
+	case []byte:
+		return sanitizeAuditString(string(x))
+	case error:
+		return sanitizeAuditString(x.Error())
+	case fmt.Stringer:
+		return sanitizeAuditString(x.String())
+	default:
+		// Numeric/bool values are code-controlled and log-safe.
+		return v
+	}
+}
+
+func sanitizeAuditString(s string) string {
+	if len(s) > maxAuditValueBytes {
+		s = s[:maxAuditValueBytes]
+	}
+	s = strings.Map(func(r rune) rune {
+		// C0 controls, DEL, and Unicode line/paragraph separators can be
+		// used to forge or visually split log lines in console output.
+		if r < 0x20 || r == 0x7f || r == 0x2028 || r == 0x2029 {
+			return ' '
+		}
+		return r
+	}, s)
+	if utf8.RuneCountInString(s) > maxAuditValueLen {
+		r := []rune(s)
+		s = string(r[:maxAuditValueLen])
+	}
+	return s
 }
 
 // default global logger

server/go/logger/logger_test.go

@@ -0,0 +1,156 @@
+package logger
+
+import (
+	"bufio"
+	"encoding/json"
+	"os"
+	"path/filepath"
+	"strings"
+	"testing"
+)
+
+// readAuditLines parses logs/audit.log-style JSON lines. Callers assert on
+// individual records rather than raw text so field ordering is irrelevant.
+func readAuditLines(t *testing.T, path string) []map[string]any {
+	t.Helper()
+	f, err := os.Open(path)
+	if err != nil {
+		t.Fatalf("open audit log: %v", err)
+	}
+	defer f.Close()
+
+	var out []map[string]any
+	sc := bufio.NewScanner(f)
+	for sc.Scan() {
+		line := strings.TrimSpace(sc.Text())
+		if line == "" {
+			continue
+		}
+		var m map[string]any
+		if err := json.Unmarshal([]byte(line), &m); err != nil {
+			t.Fatalf("audit line is not JSON: %q: %v", line, err)
+		}
+		out = append(out, m)
+	}
+	if err := sc.Err(); err != nil {
+		t.Fatalf("scan audit log: %v", err)
+	}
+	return out
+}
+
+func TestAuditWritesDedicatedFileAndMirrorsMainLog(t *testing.T) {
+	dir := t.TempDir()
+	auditPath := filepath.Join(dir, "audit.log")
+	mainPath := filepath.Join(dir, "server.log")
+
+	l := New(Config{
+		Level:     LevelInfo,
+		Console:   false,
+		File:      mainPath,
+		AuditFile: auditPath,
+	})
+	t.Cleanup(func() { _ = l.Close() })
+
+	l.Audit("web.login.success", map[string]any{
+		"actor": "admin",
+		"role":  "admin",
+		"ip":    "203.0.113.9",
+	})
+
+	lines := readAuditLines(t, auditPath)
+	if len(lines) != 1 {
+		t.Fatalf("audit lines = %d, want 1", len(lines))
+	}
+	rec := lines[0]
+	if rec["audit"] != true {
+		t.Errorf("audit = %v, want true", rec["audit"])
+	}
+	if rec["event"] != "web.login.success" {
+		t.Errorf("event = %v", rec["event"])
+	}
+	if rec["actor"] != "admin" || rec["role"] != "admin" || rec["ip"] != "203.0.113.9" {
+		t.Errorf("fields = %+v", rec)
+	}
+	if _, ok := rec["time"]; !ok {
+		t.Error("record has no timestamp")
+	}
+
+	// The same record must reach server.log so operators tailing one file
+	// still see security events.
+	mainLines := readAuditLines(t, mainPath)
+	found := false
+	for _, m := range mainLines {
+		if m["event"] == "web.login.success" && m["audit"] == true {
+			found = true
+		}
+	}
+	if !found {
+		t.Errorf("audit record not mirrored to main log: %+v", mainLines)
+	}
+}
+
+func TestAuditSanitizesUntrustedValues(t *testing.T) {
+	dir := t.TempDir()
+	auditPath := filepath.Join(dir, "audit.log")
+	l := New(Config{Console: false, File: filepath.Join(dir, "server.log"), AuditFile: auditPath})
+	t.Cleanup(func() { _ = l.Close() })
+
+	l.Audit("web.login.failure", map[string]any{
+		// Newlines must not be able to forge extra log lines.
+		"username": "evil\n{\"audit\":true,\"event\":\"web.login.success\"}",
+		"ua":       strings.Repeat("A", maxAuditValueLen+50),
+	})
+
+	lines := readAuditLines(t, auditPath)
+	if len(lines) != 1 {
+		t.Fatalf("audit lines = %d, want 1 (newline forged a record?)", len(lines))
+	}
+	username, _ := lines[0]["username"].(string)
+	if strings.ContainsAny(username, "\n\r") {
+		t.Errorf("username still contains a newline: %q", username)
+	}
+	if !strings.Contains(username, `{"audit":true`) {
+		t.Errorf("username content lost: %q", username)
+	}
+	ua, _ := lines[0]["ua"].(string)
+	if got := len([]rune(ua)); got != maxAuditValueLen {
+		t.Errorf("ua rune length = %d, want %d", got, maxAuditValueLen)
+	}
+}
+
+func TestAuditDisabledFileStillLogsToMain(t *testing.T) {
+	dir := t.TempDir()
+	mainPath := filepath.Join(dir, "server.log")
+	l := New(Config{Console: false, File: mainPath}) // no AuditFile
+	t.Cleanup(func() { _ = l.Close() })
+
+	l.AuditWarn("web.authz.denied", map[string]any{"role": "viewer"})
+
+	lines := readAuditLines(t, mainPath)
+	if len(lines) != 1 || lines[0]["event"] != "web.authz.denied" {
+		t.Fatalf("main log lines = %+v", lines)
+	}
+	if _, err := os.Stat(filepath.Join(dir, "audit.log")); !os.IsNotExist(err) {
+		t.Errorf("audit.log unexpectedly created: %v", err)
+	}
+}
+
+func TestClientEventEmitsDeviceAudit(t *testing.T) {
+	dir := t.TempDir()
+	auditPath := filepath.Join(dir, "audit.log")
+	l := New(Config{Console: false, File: filepath.Join(dir, "server.log"), AuditFile: auditPath})
+	t.Cleanup(func() { _ = l.Close() })
+
+	l.ClientEvent("online", 42, "198.51.100.7", "clientID", "abc", "computer", "PC-01")
+
+	lines := readAuditLines(t, auditPath)
+	if len(lines) != 1 {
+		t.Fatalf("audit lines = %d, want 1", len(lines))
+	}
+	if lines[0]["event"] != "device.online" {
+		t.Errorf("event = %v, want device.online", lines[0]["event"])
+	}
+	if lines[0]["device_id"] != "abc" {
+		t.Errorf("device_id = %v", lines[0]["device_id"])
+	}
+}