OpsLog/internal/applog/applog.go

// Package applog routes the app's diagnostic output to a rotating log
// file inside the user's data dir. Wails builds with the Windows GUI
// subsystem by default — fmt.Println output is dropped, so launching
// from cmd never showed anything. The file gives us a reliable place to
// inspect what the UDP listener / cluster / CAT layer is doing.
package applog

import (
	"fmt"
	"io"
	"log"
	"os"
	"path/filepath"
	"runtime/debug"
	"sync"
	"time"
)

var (
	mu        sync.Mutex
	file      *os.File
	path      string
	written   int64    // bytes in the CURRENT file, for the size check in Printf
	crashFile *os.File // kept open so the runtime can write a crash traceback to it
)

// maxLogBytes is where the file rolls over, at startup AND while running.
// A variable, not a constant, so the rotation can be exercised in a test without
// writing ten megabytes to do it.
var maxLogBytes int64 = 10 * 1024 * 1024

// Init opens (creates) the log file in dataDir. On rotation we truncate
// at startup if the file is too big; for now it's a single file, no
// rolling — the volume is low (a few KB per session).
func Init(dataDir string) (string, error) {
	mu.Lock()
	defer mu.Unlock()

	if file != nil {
		return path, nil
	}
	if dataDir == "" {
		return "", fmt.Errorf("empty data dir")
	}
	if err := os.MkdirAll(dataDir, 0o755); err != nil {
		return "", err
	}
	logPath := filepath.Join(dataDir, "opslog.log")
	// One-shot rename for users coming from the HamLog era.
	if _, err := os.Stat(logPath); os.IsNotExist(err) {
		oldLog := filepath.Join(dataDir, "hamlog.log")
		if _, err := os.Stat(oldLog); err == nil {
			_ = os.Rename(oldLog, logPath)
		}
	}
	// Rotate (don't delete) once the file grows past maxLogBytes: rename it to
	// opslog.log.1 so the PREVIOUS session's log survives. Deleting it outright used
	// to erase exactly the diagnostics we needed when a user reported an issue from
	// the session that just ended. One generation kept — enough, without unbounded growth.
	if fi, err := os.Stat(logPath); err == nil && fi.Size() > maxLogBytes {
		_ = os.Remove(logPath + ".1") // drop the older generation
		if err := os.Rename(logPath, logPath+".1"); err != nil {
			_ = os.Remove(logPath) // rename failed (locked?) → fall back to the old behaviour
		}
	}
	f, err := os.OpenFile(logPath, os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0o644)
	if err != nil {
		return "", err
	}
	file = f
	path = logPath

	// Capture a full traceback on a FATAL crash (a Go panic that escapes our
	// recover()s, or a runtime-fatal error like a concurrent map write, or a
	// Windows access violation routed through the Go signal handler) into a
	// dedicated file the runtime writes directly — so otherwise-silent process
	// deaths leave a stack we can read.
	if cf, cerr := os.OpenFile(filepath.Join(dataDir, "opslog-crash.log"),
		os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0o644); cerr == nil {
		crashFile = cf
		_ = debug.SetCrashOutput(cf, debug.CrashOptions{})
	}

	// Redirect log.Print* and the standard logger to the file too, so
	// any third-party output stays consistent.
	log.SetOutput(io.MultiWriter(file, os.Stderr))
	log.SetFlags(log.LstdFlags | log.Lmicroseconds)

	fmt.Fprintf(file, "\n────── OpsLog start %s ──────\n", time.Now().Format(time.RFC3339))
	return logPath, nil
}

// Printf writes a formatted line with a timestamp. Caller's format may
// or may not end with a newline — we strip a trailing one before adding
// our own, so log entries always look like "HH:MM:SS.mmm msg\n".
func Printf(format string, args ...any) {
	mu.Lock()
	defer mu.Unlock()
	stamp := time.Now().Format("15:04:05.000")
	msg := fmt.Sprintf(format, args...)
	for len(msg) > 0 && (msg[len(msg)-1] == '\n' || msg[len(msg)-1] == '\r') {
		msg = msg[:len(msg)-1]
	}
	if file != nil {
		n, _ := fmt.Fprintf(file, "%s %s\n", stamp, msg)
		written += int64(n)
		rotateIfBigLocked()
	}
	// Also dump to stderr in case the binary was launched with a console
	// attached (wails dev, custom build).
	fmt.Fprintf(os.Stderr, "%s %s\n", stamp, msg)
}

// rotateIfBigLocked rolls the file over mid-session once it passes maxLogBytes.
//
// The check used to happen at STARTUP only, on the reasonable belief that a
// session writes a few kilobytes. The CI-V wire trace disproved it: left on for
// a day it wrote 416 MB, and nothing would have stopped it before the disk did.
// A log that has to be rotated by quitting the program is not a bound.
//
// Same one-generation scheme as the startup rotation, so the previous stretch
// survives — which is the half an operator usually needs, the part just before
// the thing they are reporting.
//
// Caller holds mu.
func rotateIfBigLocked() {
	if written < maxLogBytes || file == nil || path == "" {
		return
	}
	fmt.Fprintf(file, "%s ── log reached %d MB, rotating to %s.1 ──\n",
		time.Now().Format("15:04:05.000"), maxLogBytes/(1024*1024), filepath.Base(path))
	_ = file.Close()
	file = nil
	_ = os.Remove(path + ".1")
	if err := os.Rename(path, path+".1"); err != nil {
		// Rename refused (the file is held open elsewhere, a virus scanner): keep
		// writing to the old handle rather than losing the log entirely, and try
		// again in another maxLogBytes rather than on every single line.
		f, oerr := os.OpenFile(path, os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0o644)
		if oerr == nil {
			file = f
		}
		written = 0
		return
	}
	f, err := os.OpenFile(path, os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0o644)
	if err != nil {
		return // nothing more to be done; the next Printf simply writes nowhere
	}
	file = f
	written = 0
	fmt.Fprintf(file, "%s ── continued from %s.1 ──\n",
		time.Now().Format("15:04:05.000"), filepath.Base(path))
}

// Path returns where the file is so the UI can surface it.
func Path() string {
	mu.Lock()
	defer mu.Unlock()
	return path
}

// Close flushes and releases the handle. Called from shutdown.
func Close() {
	mu.Lock()
	defer mu.Unlock()
	if file != nil {
		_ = file.Close()
		file = nil
	}
	// The crash file is held open for the whole run so the runtime can dump a
	// traceback into it without allocating; on the way out it has to be released
	// like any other handle, or the data directory cannot be moved or removed.
	if crashFile != nil {
		// The RUNTIME holds its own duplicate of this handle (SetCrashOutput), so
		// closing ours releases nothing on Windows — the data directory stays
		// locked. Hand the runtime a nil first. Anything fatal in the last moments
		// of shutdown is no longer captured, which is the right trade at a point
		// where the databases are already closed.
		_ = debug.SetCrashOutput(nil, debug.CrashOptions{})
		_ = crashFile.Close()
		crashFile = nil
	}
	path = ""
	written = 0
}