monitor: run log-plugin subprocesses off the tick (cached eval) — fix loop stall

[svaroqui]

Problem (proven from a live goroutine dump on dbaas-fr-2)

tickBody → CheckLogPlugins → RunLogPlugins → ExternalLogPlugin.Evaluate shells out to the plugin binary (os/exec) inline in the monitor tick. The dump showed tickBody parked in os.Process.Wait inside cmd.Output(). With N plugins × M servers run serially in the tick, a slow/unresponsive server makes the tick's cadence collapse to minutes → heartbeat stalls → GWARN001 (the HB supervision correctly reports it). This is the violation of "the monitor loop must never block on anything."

Fix

Move only the Evaluate() subprocess off the tick: cachedPluginEval() caches the result per (server, plugin) and refreshes it in a background goroutine. The plugin binaries, wire protocol, and Evaluate itself are untouched.

The entire apply half is unchanged and still runs every tick from the cached result — findings → SecurityStateMachine/WorkloadStateMachine/SchemaStateMachine/StateMachine, score, WTAG, graphite.

Why it's flap-safe

Those plugin state machines are ClearState'd every tick (cluster.go:1470-1472). Because the apply still runs every tick (from cache), every finding is re-asserted every tick and never resolves-and-reopens. A naive fire-and-forget of the whole CheckLogPlugins would have flapped all findings (dynamic per-server composite keys, not listable in pstatesN) — this cached-read design avoids that.

Notes

• Cold start: a plugin's findings appear one tick after its first background eval completes.
• Refresh cadence: pluginEvalIntervalTicks = 15 (const; can become a flag).
• inFlight guard prevents duplicate concurrent evals; goroutines are bounded by the plugin's own 5s+WaitDelay.

Tests

• New TestCachedPluginEval_OffTickAndNoFlap: eval runs async (first call empty), then cached, and is not re-run within the interval.
• Full Plugin/Security/Workload/Schema suite passes; no existing test relied on inline evaluation.

Delicate state code — should be validated on the OpenSVC topology matrix before it ships.

[tanji]

Code review findings

Scope: cluster/srv_log_plugins.go (and cluster/srv.go) — moves log-plugin evaluation off the synchronous monitoring tick into a background goroutine with a cache (pluginEval / pluginEvalMu), guarded by an inFlight bool.

1. Data race on SpikeCache — cluster/srv_log_plugins.go:156

The shared *logplugin.SpikeCache pointer is passed into src.SpikeCache and captured by the new background goroutine, which calls Evaluate → DetectSpike, mutating cache.Result/CheckedAt/OpenedAt with no lock. The same tick's synchronous code (lines 407-421) reads cache.IsHeld()/cache.OpenedAt on the same object with no lock — a concurrent unsynchronized read/write on a multi-field struct (time.Time is multi-word), flagged by go test -race, capable of a torn read that corrupts WARN0205 hold/resolve decisions. This race didn't exist before the PR because Evaluate ran synchronously in the same call that read the cache.

2. Panic leaks inFlight = true forever — cluster/srv_log_plugins.go:95

If p.Evaluate(src) panics inside the background goroutine, the deferred cluster.LogPanicToFile recovers and logs, but execution never reaches the code that sets e.inFlight = false. That plugin's refresh is permanently disabled for that server until process restart.

3. ~14/15 ticks silently discarded — cluster/srv_log_plugins.go:222

cachedPluginEval only actually invokes Evaluate on the tick that triggers a refresh (roughly 1 in 15); the fresh src snapshot built every other tick is discarded. Transient conditions (SQL error bursts, metadata-lock waits) that appear and clear within the 15-tick window are never evaluated — a regression from the old synchronous-every-tick behavior.

4. Stale lastTick after StateMachine reset — cluster/srv_log_plugins.go:91

On cluster/StateMachine re-init, heartbeats resets to 0 while existing pluginEval entries retain a large stale lastTick, making hb - e.lastTick deeply negative and staying below pluginEvalIntervalTicks for as many ticks as the previous heartbeat count — silently disabling refresh for a long time with no log signal.

5. No self-imposed timeout — cluster/srv_log_plugins.go:77

cachedPluginEval imposes no timeout/deadline of its own on p.Evaluate(src), relying entirely on each LogPlugin implementation to self-bound. A hanging Evaluate leaves inFlight stuck true and leaks the goroutine for the life of the process.

6. Thundering herd on cold start — cluster/srv_log_plugins.go:91

On cold start (or after anything that clears server.pluginEval), every plugin for every server has !e.have simultaneously true, so the next tick fires one background subprocess goroutine per (plugin, server) pair all at once — N×M concurrent os/exec forks instead of the bounded execution that existed before, spiking CPU/process count right as the system starts up.

7. Full snapshot built every tick regardless of use — cluster/srv_log_plugins.go:147

The full LogSource snapshot (error/SQL/slow/audit logs, PFS queries, process list, metadata locks, binlog events, server vars/status, DB users, etc.) is built unconditionally every tick for every plugin — several fields under mutexes (HttpLog.L, PFSExplainCacheMu, BinlogEventLog.L) — even though it's discarded ~14/15 ticks and even for disabled/prerequisite-missing plugins (those checks happen after the snapshot is built).

8. Duplicate concurrency pattern — cluster/srv.go:230

The new pluginEval/pluginEvalMu cache reimplements a bespoke bool-flag-guarded background-refresh mechanism, duplicating the adjacent, already-established pfsExplainCancel (context.CancelFunc) pattern on the same struct, which solves the identical "slow work must not block the monitor tick" problem with proper cancellation. The new path has no cancellation, making findings #2/#5 harder to recover from operationally.

---

Priority for merge: #1 (data race) and #2 (permanent freeze on panic) are correctness bugs, not just design nits, and should block merge until addressed.

Posted via automated code review.