Files
panel/agent/internal/dispatch/stats.go
T
2026-07-14 23:37:25 -07:00

399 lines
16 KiB
Go
Raw Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
package dispatch
import (
"context"
"encoding/json"
"fmt"
"io"
"time"
"google.golang.org/protobuf/types/known/timestamppb"
panelv1 "github.com/dbledeez/panel/proto/panel/v1"
)
// Per-instance stats polling. Docker streams a JSON frame ~once per
// second; we throttle to one upstream emit per statsEmitInterval so the
// event bus isn't flooded. CPU% uses the frame's curprevious delta
// directly (Docker includes precpu_stats on streamed frames).
// 3s is snappy enough to watch RAM climb during ARK world-load (12-15 GB
// in under a minute) without flooding the SSE bus. Older 10s value made
// the dashboard feel laggy when memory was actually moving fast.
const statsEmitInterval = 3 * time.Second
// ARK SA memory guardrails — two-stage so we can flush saves cleanly
// before having to SIGKILL.
//
// Healthy ARK SA world: 10-15 GB resident. 16-30 GB during save-flush
// peaks is normal on a populated cluster. 45 GB is the warning level;
// 60 GB is the hard kill that protects the host from OOM (which would
// take down all sibling ARKs + postgres + the panel itself).
//
// 2026-05-25 history: the previous single-threshold 40 GB → 5s SIGKILL
// path corrupted at least three SQLite-backed `.ark` saves over the
// 2026-05-19 → 2026-05-25 window because the SIGKILL hit while a
// SaveWorld was mid-flush (FAtlasSaveManager::LoadOperationSql crash on
// next boot — null page read in the half-written SQLite store).
//
// The two-stage guard:
//
// At arkRAMWarnLimit (45 GB) — fired AT MOST ONCE per container life:
// 1. Broadcast a 60s heads-up to in-game players via RCON
// 2. SaveWorld (lets ARK flush cleanly)
// 3. Wait 60s for the save + warning window
// 4. runtime.Stop with 120s grace (clean shutdown path)
// The container then stays Exited; operator restarts when ready, no
// torn save, no progress loss beyond what the SaveWorld captured.
//
// At arkRAMHardLimit (60 GB) — fires if the warn path didn't help:
// SIGKILL via runtime.Stop with 30s grace. Save MAY be torn here;
// this is the host-protection layer, accepted as last-resort.
//
// The warn level fires at most once per container life via the
// rec.memGuardWarned atomic — once we've committed to a graceful stop,
// the hard limit isn't allowed to also fire and interrupt the SaveWorld.
const arkRAMWarnLimit uint64 = 45 * 1024 * 1024 * 1024
const arkRAMHardLimit uint64 = 60 * 1024 * 1024 * 1024
// gracefulStopGracePeriod is the docker-stop grace given to the
// graceful warn path. ARK's SaveWorld can take 30-60s on a populated
// world; 120s is enough headroom for the flush + the watchdog's DoExit.
const gracefulStopGracePeriod = 120 * time.Second
// emergencyStopGracePeriod is the docker-stop grace for the 60 GB hard
// path. 30s (was 5s) gives the engine a real shot at flushing in-flight
// state before SIGKILL — the host-OOM risk that motivated the original
// 5s grace doesn't materialize this fast in practice.
const emergencyStopGracePeriod = 30 * time.Second
// dockerStatsFrame is the minimum subset of Docker's /containers/<id>/stats
// response we need. Kept as a local shape so we don't depend on which
// version of github.com/docker/docker renamed the struct this week.
type dockerStatsFrame struct {
CPUStats struct {
// IMPORTANT: every nested field needs an explicit json tag.
// Go's unmarshal is case-insensitive but does NOT translate
// CamelCase ↔ snake_case. Without `json:"total_usage"`, the
// field reads as 0 because Docker emits the snake_case key
// and we'd be looking for "TotalUsage" / "totalusage". This
// bug shipped for months — every container reported 0% CPU.
CPUUsage struct {
TotalUsage uint64 `json:"total_usage"`
} `json:"cpu_usage"`
SystemCPUUsage uint64 `json:"system_cpu_usage"`
OnlineCPUs uint32 `json:"online_cpus"`
} `json:"cpu_stats"`
PreCPUStats struct {
CPUUsage struct {
TotalUsage uint64 `json:"total_usage"`
} `json:"cpu_usage"`
SystemCPUUsage uint64 `json:"system_cpu_usage"`
} `json:"precpu_stats"`
MemoryStats struct {
Usage uint64 `json:"usage"`
Limit uint64 `json:"limit"`
// Docker's `usage` includes file-system page cache, which can
// balloon to multi-GB on read-heavy workloads (ARK SA's mod +
// asset reads inflate it to 25 GB on a 12 GB RSS workload).
// `docker stats` CLI subtracts cache/inactive_file to match
// what operators expect. We mirror that.
// - cgroups v1: usage - stats.cache
// - cgroups v2: usage - stats.inactive_file
// Both keys are in the same nested map; whichever is present
// is the one our cgroup version exposes.
Stats struct {
Cache uint64 `json:"cache"` // cgroups v1
InactiveFile uint64 `json:"inactive_file"` // cgroups v2
RSS uint64 `json:"rss"` // cgroups v1
Anon uint64 `json:"anon"` // cgroups v2 (active anon)
} `json:"stats"`
} `json:"memory_stats"`
Networks map[string]struct {
RxBytes uint64 `json:"rx_bytes"`
TxBytes uint64 `json:"tx_bytes"`
} `json:"networks"`
PidsStats struct {
Current uint32 `json:"current"`
} `json:"pids_stats"`
}
func (d *Dispatcher) streamStats(ctx context.Context, rec *instanceRecord) {
rc, err := d.runtime.StatsStream(ctx, rec.ContainerID)
if err != nil {
d.log.Warn("stats stream open failed", "instance_id", rec.InstanceID, "err", err)
return
}
defer rc.Close()
d.log.Info("stats stream opened", "instance_id", rec.InstanceID)
emitCount := 0
defer func() { d.log.Info("stats stream closed", "instance_id", rec.InstanceID, "emitted", emitCount) }()
dec := json.NewDecoder(rc)
lastEmit := time.Time{}
for {
if ctx.Err() != nil {
return
}
var f dockerStatsFrame
if err := dec.Decode(&f); err != nil {
if err != io.EOF && ctx.Err() == nil {
d.log.Debug("stats decode ended", "instance_id", rec.InstanceID, "err", err)
}
return
}
if time.Since(lastEmit) < statsEmitInterval {
continue
}
memUsed := d.sendStats(rec.InstanceID, &f)
lastEmit = time.Now()
emitCount++
// ARK runaway-memory guardrails. Two stages: warn (45 GB) tries a
// graceful flush; hard (60 GB) SIGKILLs to protect the host.
// Both paths set rec.stopping inside their handler so subsequent
// samples short-circuit there.
if rec.ModuleID == "ark-sa" {
if memUsed > arkRAMHardLimit {
go d.emergencyRestart(rec, fmt.Sprintf(
"ARK RAM hit %.1f GB (hard limit %d GB) — bouncing to protect host",
float64(memUsed)/1024/1024/1024, arkRAMHardLimit/1024/1024/1024))
return
}
if memUsed > arkRAMWarnLimit && rec.memGuardWarned.CompareAndSwap(false, true) {
go d.gracefulMemoryRestart(rec, fmt.Sprintf(
"ARK RAM hit %.1f GB (warn limit %d GB) — flushing save + graceful restart",
float64(memUsed)/1024/1024/1024, arkRAMWarnLimit/1024/1024/1024))
// Don't return — keep streaming so the hard limit can still
// fire if RAM keeps climbing past 60 GB during the 60s flush
// window. The memGuardWarned latch prevents the warn path
// from re-arming, but the hard path is the host-protection
// backstop and must remain live.
}
}
}
}
func (d *Dispatcher) sendStats(instanceID string, f *dockerStatsFrame) uint64 {
// CPU%: delta total / delta system * online_cpus * 100.
// First frame's precpu_stats is zero so cpuPct comes out 0 — fine.
var cpuPct float64
cpuDelta := int64(f.CPUStats.CPUUsage.TotalUsage) - int64(f.PreCPUStats.CPUUsage.TotalUsage)
sysDelta := int64(f.CPUStats.SystemCPUUsage) - int64(f.PreCPUStats.SystemCPUUsage)
hostCpus := f.CPUStats.OnlineCPUs
if sysDelta > 0 && cpuDelta > 0 {
cpus := float64(hostCpus)
if cpus < 1 {
cpus = 1
}
cpuPct = float64(cpuDelta) / float64(sysDelta) * cpus * 100.0
}
var rx, tx uint64
for _, n := range f.Networks {
rx += n.RxBytes
tx += n.TxBytes
}
// "Real" memory: subtract file cache (cgroups v1) or inactive_file
// (cgroups v2). Falls through to raw usage when neither is reported
// (Windows containers, exotic runtimes). This is what `docker stats`
// shows and what operators expect — the inflated ARK numbers (~25 GB
// vs the actual ~12 GB RSS) were the cache-included variant.
memUsed := f.MemoryStats.Usage
if f.MemoryStats.Stats.InactiveFile > 0 && f.MemoryStats.Stats.InactiveFile <= memUsed {
memUsed -= f.MemoryStats.Stats.InactiveFile
} else if f.MemoryStats.Stats.Cache > 0 && f.MemoryStats.Stats.Cache <= memUsed {
memUsed -= f.MemoryStats.Stats.Cache
}
d.sendEnv(&panelv1.AgentEnvelope{
SentAt: timestamppb.Now(),
Payload: &panelv1.AgentEnvelope_InstanceStats{
InstanceStats: &panelv1.InstanceStatsUpdate{
InstanceId: instanceID,
CpuPercent: cpuPct,
MemUsedBytes: memUsed,
MemLimitBytes: f.MemoryStats.Limit,
NetRxBytes: rx,
NetTxBytes: tx,
Pids: f.PidsStats.Current,
HostCpus: hostCpus,
At: timestamppb.Now(),
},
},
})
return memUsed
}
// gracefulMemoryRestart is the 45 GB warn path. Tries to land a clean
// SaveWorld before bouncing the container so the next boot doesn't face
// a torn SQLite save. Sequence:
//
// 1. Latch rec.stopping so other paths back off.
// 2. Emit a panel log line + INSTANCE_STATUS_STOPPING state.
// 3. RCON Broadcast: "[Panel] high memory — saving and restarting in 60s"
// 4. RCON SaveWorld
// 5. Sleep 60s (gives players warning + engine time to write the save)
// 6. Cancel tracker/log goroutines, runtime.Restart with 120s grace.
//
// Uses Restart NOT Stop: a plain Stop on an `unless-stopped` container
// is honored by docker as an operator stop — the container then stays
// Exited until someone manually restarts it. That regression took
// Ragnarok offline for 17 hours after the 02:02 PDT warn fire on
// 2026-05-25 (see HANDOFF "Last meaningfully updated"). Restart bounces
// the container as a transient event so it comes back up automatically;
// the operator just sees a brief blip + the "[panel] MEMORY-WARN" line.
//
// If any RCON step fails (engine wedged, RCON socket dead), fall through
// to the restart anyway — we still want the engine down + back up. The
// 120s docker grace gives the engine a real shot at a clean DoExit even
// when RCON is the broken thing.
func (d *Dispatcher) gracefulMemoryRestart(rec *instanceRecord, reason string) {
if !rec.stopping.CompareAndSwap(false, true) {
return
}
d.log.Warn("ark memory warn — graceful restart", "instance_id", rec.InstanceID, "reason", reason)
d.sendEnv(&panelv1.AgentEnvelope{
SentAt: timestamppb.Now(),
Payload: &panelv1.AgentEnvelope_Log{Log: &panelv1.LogLine{
InstanceId: rec.InstanceID,
Stream: "stderr",
At: timestamppb.Now(),
Line: "[panel] MEMORY-WARN: " + reason,
}},
})
d.sendInstanceState(rec.InstanceID, panelv1.InstanceStatus_INSTANCE_STATUS_STOPPING, 0, "graceful memory restart: "+reason)
// Best-effort RCON broadcast + SaveWorld. Use a short per-call
// timeout so a wedged RCON socket doesn't block the whole graceful
// path. tracker.Exec redials internally, so a closed socket from
// idle-disconnect won't burn the attempt.
if rec.Tracker != nil {
bctx, bcancel := context.WithTimeout(context.Background(), 5*time.Second)
if _, err := rec.Tracker.Exec(bctx, "Broadcast [Panel] High memory detected. Server saving and restarting in 60 seconds."); err != nil {
d.log.Warn("rcon broadcast failed during graceful memory restart", "instance_id", rec.InstanceID, "err", err)
}
bcancel()
sctx, scancel := context.WithTimeout(context.Background(), 10*time.Second)
if _, err := rec.Tracker.Exec(sctx, "SaveWorld"); err != nil {
d.log.Warn("rcon SaveWorld failed during graceful memory restart", "instance_id", rec.InstanceID, "err", err)
}
scancel()
}
// Wait the warning window — players see the broadcast, engine
// finishes writing the save. Sleeping in the goroutine is fine;
// the stats loop continues to monitor for the 60 GB hard limit
// in case RAM keeps climbing during the wait.
time.Sleep(60 * time.Second)
// Cancel ancillary goroutines so they don't fight the bounce.
// They'll be re-armed by watchExit when the restart settles.
d.mu.Lock()
if rec.TrackerCancel != nil {
rec.TrackerCancel()
rec.TrackerCancel = nil
}
if rec.LogCancel != nil {
rec.LogCancel()
rec.LogCancel = nil
}
d.mu.Unlock()
ctx, cancel := context.WithTimeout(context.Background(), gracefulStopGracePeriod+30*time.Second)
defer cancel()
if err := d.runtime.Restart(ctx, rec.ContainerID, gracefulStopGracePeriod); err != nil {
d.log.Error("graceful memory restart runtime failure", "instance_id", rec.InstanceID, "err", err)
// Restart failed — surface to operator so they know to investigate.
d.sendEnv(&panelv1.AgentEnvelope{
SentAt: timestamppb.Now(),
Payload: &panelv1.AgentEnvelope_Log{Log: &panelv1.LogLine{
InstanceId: rec.InstanceID,
Stream: "stderr",
At: timestamppb.Now(),
Line: "[panel] MEMORY-WARN restart failed: " + err.Error(),
}},
})
}
// Clear both the stopping and memGuardWarned latches so future
// memory-warn fires can re-arm on this container's next life.
rec.stopping.Store(false)
rec.memGuardWarned.Store(false)
}
// emergencyRestart bounces a runaway container outside the normal
// handleStop path. Difference from handleStop: 30s grace (not 60s),
// runs even when no operator request is in flight, and emits a clear
// log line so the dashboard's Console tab shows WHY this happened.
//
// Uses Restart NOT Stop — see gracefulMemoryRestart for the rationale.
// A plain Stop on `unless-stopped` containers parks them Exited until
// manually started; the panel operator has no way to know they need to
// click Start. Bouncing the container keeps the service available, lets
// the engine recover into a fresh process with no leak state, and the
// "[panel] AUTO-KILL" log line is preserved for after-the-fact diagnosis.
// If the underlying leak is persistent, RAM will climb again and the
// guard will fire again — that's the operator's signal to investigate.
//
// 2026-05-25: bumped from 5s → 30s grace. The 5s window guaranteed
// SIGKILL mid-save when this fired during a SaveWorld, and that's
// what was producing the FAtlasSaveManager corruption pattern. 30s
// is enough for the engine to finish a save in flight without giving
// up host-OOM protection.
//
// Idempotent via rec.stopping: the stats loop fires this from a goroutine
// every 3s while RAM is over the limit, but the second+ invocations
// short-circuit at the stopping check so we don't pile up Stop calls
// against a container that's already heading down.
func (d *Dispatcher) emergencyRestart(rec *instanceRecord, reason string) {
if !rec.stopping.CompareAndSwap(false, true) {
return
}
d.log.Warn("emergency restart", "instance_id", rec.InstanceID, "reason", reason)
// Surface to operator via log line + state update.
d.sendEnv(&panelv1.AgentEnvelope{
SentAt: timestamppb.Now(),
Payload: &panelv1.AgentEnvelope_Log{Log: &panelv1.LogLine{
InstanceId: rec.InstanceID,
Stream: "stderr",
At: timestamppb.Now(),
Line: "[panel] AUTO-KILL: " + reason,
}},
})
d.sendInstanceState(rec.InstanceID, panelv1.InstanceStatus_INSTANCE_STATUS_STOPPING, 0, "auto-kill: "+reason)
// Cancel ancillary goroutines so they don't fight the bounce.
// They'll be re-armed by watchExit when the restart settles.
d.mu.Lock()
if rec.TrackerCancel != nil {
rec.TrackerCancel()
rec.TrackerCancel = nil
}
if rec.LogCancel != nil {
rec.LogCancel()
rec.LogCancel = nil
}
d.mu.Unlock()
ctx, cancel := context.WithTimeout(context.Background(), emergencyStopGracePeriod+30*time.Second)
defer cancel()
if err := d.runtime.Restart(ctx, rec.ContainerID, emergencyStopGracePeriod); err != nil {
d.log.Error("emergency restart runtime failure", "instance_id", rec.InstanceID, "err", err)
d.sendEnv(&panelv1.AgentEnvelope{
SentAt: timestamppb.Now(),
Payload: &panelv1.AgentEnvelope_Log{Log: &panelv1.LogLine{
InstanceId: rec.InstanceID,
Stream: "stderr",
At: timestamppb.Now(),
Line: "[panel] AUTO-KILL restart failed: " + err.Error(),
}},
})
}
// Clear both latches so future signals can re-arm on the bounced container.
rec.stopping.Store(false)
rec.memGuardWarned.Store(false)
}