diff --git a/README.md b/README.md index 4dc439ab..6a4958b4 100644 --- a/README.md +++ b/README.md @@ -11,10 +11,11 @@ server events, and your own resources decide what to do with them. > **Status: proof of concept.** Settings, the panel and the integration contract may still change > between versions. -- **Supervision.** Start, stop and restart with a graceful stop. Crashes and hangs are detected and - recovered from, a crash loop stops the retries (5 failures within 10 minutes, or 5 starts in a row - that never got ready), and FXServer's whole process tree stops with it. A server stuck for 6 minutes - is restarted; the delay can be raised, or hang detection turned off. +- **Supervision.** Start, stop and restart with a graceful stop, which waits for the resources that + ask it to until they have saved. Crashes and hangs are detected and recovered from, a crash loop + stops the retries (5 failures within 10 minutes, or 5 starts in a row that never got ready), and + FXServer's whole process tree stops with it. A server stuck for 6 minutes is restarted; the delay + can be raised, or hang detection turned off. - **Live console.** Search and filters, commands gated by permission, secrets masked, daily log files. - **Resources.** Every resource of the running server with its state, live, and a start, a stop or a restart of each, the resources that stop with it named before you confirm. @@ -217,6 +218,30 @@ detection back on never kills a server that was silent before. A crash is anothe FXServer's process exits on its own, Observer restarts it, whatever these settings say, until a crash loop stops the retries. +### Stops that wait for your resources + +Before FXServer quits, Observer raises `observer:shuttingDown` in your resources, waits 5 seconds, +then sends `quit`. A resource that saves for longer can hold the stop: it calls the bridge's +`holdShutdown` export once, as it starts, and `releaseShutdown` each time it has saved. Observer then +sends `quit` once every resource that holds the stop has released it. The +[integration contract](resource/CONTRACT.md#holding-a-stop) has the two calls and each case. + +The wait has a limit, **Server → Wait for resources at a stop**: 60 seconds by default, from 5 +seconds to 10 minutes, the owner's to set, applied from the next stop. Past it FXServer quits +anyway, and the console and the audit log name the resources that had not released the stop. Set +to 5 seconds, no resource is waited for longer than before. + +While a stop waits, the status bar above every page names the resources it waits for and how long +is left, and whoever may start and stop the server can have FXServer **Quit now**; the audit log +keeps who did, with the resources left behind. The launch settings list which resources of the +running server hold its stops. + +This holds for every graceful stop: a stop or a restart from the panel or the host's window, the +schedule's restarts and the single ones someone planned, a build applied by a restart, and Observer +stopping, for an update or by itself. It does not hold when there is no one to wait for or no time: +after a crash, on a server that stopped responding, and when Windows closes Observer's console or +ends the session, which leaves a few seconds only. + ## systemd `observer service print-unit` prints a unit that runs this binary with this configuration, as the @@ -238,7 +263,9 @@ The unit: update (`RestartForceExitStatus=75`, `SuccessExitStatus=75`); a unit printed before updates existed restarts it too, as a failure; - on stop, sends SIGTERM to Observer alone, which stops FXServer gracefully, then the rest of the - group (`KillMode=mixed`, `TimeoutStopSec=45`); + group (`KillMode=mixed`, `TimeoutStopSec=45`). While resources hold the stop, Observer asks + systemd for the time it waits (`EXTEND_TIMEOUT_USEC`, systemd 236 or later), so a unit already + installed needs no change; an older systemd ends the stop after its 45 seconds; - makes `/usr`, `/boot`, `/efi` and `/etc` read-only (`ProtectSystem=full`), with a private `/tmp`: keep Observer's folder and the server's elsewhere, such as `/srv` or a home folder. @@ -981,7 +1008,8 @@ Observer can back up the game server's database, the one oxmysql or mysql-async are copied as the dump reaches them. - **When**: before the schedule's restarts and the single restarts someone planned (the default), or before every restart; at fixed times, in the restart schedule's zone; and on request. The backup - before a restart is dumped once FXServer has stopped, when resources have saved what they held, + before a restart is dumped once FXServer has stopped, when resources have saved what they held + and released the stop if they hold it, and FXServer waits for it one minute at most by default (up to ten): past that it starts anyway, the dump goes on, and the run says so. Copies go out while FXServer runs. A crash restart never waits for a backup. @@ -1015,6 +1043,10 @@ an event, an export or one of txAdmin's events by its name. Any account reads it see the dashboard, it also says what this server does now: the contract's version, the name the bridge took for this start, and whether txAdmin's events are raised, now and from the next start. +A resource that saves when the server stops can hold the stop until it has saved, through the +bridge's `holdShutdown` and `releaseShutdown` exports: see +[Stops that wait for your resources](#stops-that-wait-for-your-resources). + Your resources can also give each connected player a label, a roleplay character's name or an ID of your own, through the bridge's `setPlayerLabel` export. The panel shows it beside the player's FiveM name, marked as your resources' word, keeps each label on the player's profile as long as their names, diff --git a/crates/fake-fxserver/src/main.rs b/crates/fake-fxserver/src/main.rs index 7793a9b2..8f30bfc9 100644 --- a/crates/fake-fxserver/src/main.rs +++ b/crates/fake-fxserver/src/main.rs @@ -87,6 +87,14 @@ //! sweep costs for each entity and for listing them, in microseconds, which cuts a sweep short //! past its budget and spaces the next ones out; `set gamename rdr3` and `onesync off` each //! leave the server without entities to list; +//! - `fake_holders `, a list separated by commas: each of them asks the bridge to hold the +//! stop as it starts, as a resource calling `holdShutdown`, and the bridge reports who holds once +//! it is ready and whenever that changes. Once the bridge raised `observer:shuttingDown`, each +//! holder releases the stop `fake_release_ms` later, or `fake_release_ms:` for one of them, +//! and never without either: a resource that forgot its `releaseShutdown`. On stdin, +//! `fake_hold ` and `fake_release ` are the two calls at the moment they are +//! typed. A holder that is stopped holds nothing any more, and a bridge started again holds +//! nothing of what the one before held; //! - on stdin: `fake_debug `, one row of a hook's report (`ev`, `np`, //! `un`, `sb`, `sbl` or `http`) printed as that resource; //! - on stdin: `fake_crash [code]`, `fake_hang`, `fake_spin` (a busy loop), `fake_print `, @@ -114,7 +122,7 @@ mod resources; #[allow(unsafe_code)] mod traces; -use std::collections::HashMap; +use std::collections::{BTreeSet, HashMap}; use std::io::{self, BufRead}; use std::net::{TcpListener, TcpStream, UdpSocket}; use std::path::{Path, PathBuf}; @@ -143,6 +151,8 @@ const SV_MAIN: &str = "UV loop: svMain"; const RESOURCE_EVENTS_MAX: usize = 64; /// How long the bridge waits after a start or a stop before it reports, unless its script says. const RESOURCES_SETTLE_MS: u64 = 500; +/// The bridge's `HOLDS_MAX`: the most resources that hold a stop at once. +const HOLDS_MAX: usize = 64; /// What the HTTP threads share with the main loop. pub struct Server { @@ -301,6 +311,10 @@ struct Fake { lists: u64, /// Every resource started, in order. started: Vec, + /// The resources that hold the stop, as the bridge keeps them. + holds: BTreeSet, + /// Once the bridge raised `observer:shuttingDown`: when each holder releases the stop by itself. + stopping: Option>, quit_at: Option, /// What `fake_spawn` started, reaped as they end. children: Vec, @@ -421,6 +435,8 @@ fn main() { unreported: Unreported::default(), lists: 0, started: Vec::new(), + holds: BTreeSet::new(), + stopping: None, quit_at: None, children: Vec::new(), connections: Vec::new(), @@ -536,6 +552,9 @@ impl Fake { self.report_resources(now); self.report_entities(now); self.beat(now); + if self.release_due(now) { + self.report_holds(&[]); + } self.count(now); self.server.tick(); thread::sleep(TICK); @@ -616,6 +635,8 @@ impl Fake { } } ("fake_label", Some(id)) => self.label(id, &args[1..]), + ("fake_hold", Some(resource)) => self.hold(resource), + ("fake_release", Some(resource)) => self.release(resource), ("fake_drop_before_join", Some(id)) => self.drop_before_join(id), ("observer_cmd", Some(hex)) if self.bridge.is_some() => self.bridge_command(hex), // A convar's name followed by a value sets it, as FXServer's console does for a convar @@ -709,11 +730,7 @@ impl Fake { } console::line(RESOURCES, &format!("Stopping resource {resource}")); self.resource_event(resource, "stop"); - if self.bridge.as_ref().is_some_and(|bridge| bridge.name == resource) { - self.bridge = None; - self.listing = None; - self.unreported = Unreported::default(); - } + self.stopped(resource); } /// FXServer's `restart`: a stop then a start, of a started resource only. @@ -787,8 +804,13 @@ impl Fake { if !self.started.iter().any(|started| started == resource) { self.started.push(resource.to_owned()); } + if listed("fake_holders") { + self.hold(resource); + } let script = self.bridge_script(resource); if let Some(contract) = script.as_deref().and_then(contract_version) { + self.holds.clear(); + self.stopping = None; let settle = script .as_deref() .and_then(|script| constant(script, "RESOURCES_SETTLE_MS")) @@ -881,6 +903,11 @@ impl Fake { &bridge.name, &json!({ "type": "observer", "kind": "resources", "started": self.started }), ); + let mut holds = json!({ "type": "observer", "kind": "holds", "stopping": false }); + if !self.holds.is_empty() { + holds["holding"] = json!(self.holds); + } + self.traces.script(&bridge.name, &holds); let name = bridge.name.clone(); self.report_resource_list(); let roster = self.server.players().roster(self.server.uptime_ms()); @@ -906,6 +933,86 @@ impl Fake { } } + /// The bridge's `holdShutdown`, called by `resource`: nothing without the bridge to call. + fn hold(&mut self, resource: &str) { + let full = self.holds.len() >= HOLDS_MAX; + if self.bridge.is_none() || full || !self.holds.insert(resource.to_owned()) { + return; + } + self.report_holds(&[]); + } + + /// The bridge's `releaseShutdown`, called by `resource`: nothing while no stop is under way. + fn release(&mut self, resource: &str) { + if self.stopping.is_some() && self.holds.remove(resource) { + self.report_holds(&[]); + } + } + + /// A resource stopped: the bridge forgets its hold, and the bridge itself forgets them all. + fn stopped(&mut self, resource: &str) { + if self.bridge.as_ref().is_some_and(|bridge| bridge.name == resource) { + self.bridge = None; + self.listing = None; + self.unreported = Unreported::default(); + self.holds.clear(); + self.stopping = None; + return; + } + if self.holds.remove(resource) { + let gone = [resource.to_owned()]; + self.report_holds(if self.stopping.is_some() { &gone } else { &[] }); + } + } + + /// The bridge raised `observer:shuttingDown`: every holder's handler runs, and one that takes + /// no time has released the stop before the bridge reports who holds it. + fn shutting_down(&mut self) { + let now = Instant::now(); + if self.stopping.is_none() { + let releases = self + .holds + .iter() + .filter_map(|resource| { + let own = self.server.number(&format!("fake_release_ms:{resource}")); + let after = own.or_else(|| self.server.number("fake_release_ms"))?; + Some((now + Duration::from_millis(after), resource.clone())) + }) + .collect(); + self.stopping = Some(releases); + } + self.release_due(now); + self.report_holds(&[]); + } + + /// Releases the stop for every holder whose time has come, and says whether one did. + fn release_due(&mut self, now: Instant) -> bool { + let Some(pending) = &mut self.stopping else { + return false; + }; + let (due, later): (Vec<_>, Vec<_>) = std::mem::take(pending) + .into_iter() + .partition(|(at, _)| now >= *at); + *pending = later; + let mut released = false; + for (_, resource) in due { + released |= self.holds.remove(&resource); + } + released + } + + /// The bridge's report of who holds the stop, an empty list left out as the bridge leaves it. + fn report_holds(&self, stopped: &[String]) { + let mut report = json!({ "type": "observer", "kind": "holds", "stopping": self.stopping.is_some() }); + if !self.holds.is_empty() { + report["holding"] = json!(self.holds); + } + if !stopped.is_empty() { + report["stopped"] = json!(stopped); + } + self.bridge_report(&report); + } + fn quit(&mut self, reason: Option<&str>) { if self.server.flag("fake_ignore_quit") || self.quit_at.is_some() { return; @@ -1296,14 +1403,19 @@ impl Fake { } Some("serverName") => self.server_name(payload["name"].as_str()), Some(_) => {} - None => console::script( - &bridge, - &format!( - "observer:{} {}", - command["event"].as_str().unwrap_or("?"), - payload - ), - ), + None => { + console::script( + &bridge, + &format!( + "observer:{} {}", + command["event"].as_str().unwrap_or("?"), + payload + ), + ); + if command["event"].as_str() == Some("shuttingDown") { + self.shutting_down(); + } + } } } diff --git a/crates/fake-fxserver/tests/artifacts.rs b/crates/fake-fxserver/tests/artifacts.rs index 44ff2412..b3516d9b 100644 --- a/crates/fake-fxserver/tests/artifacts.rs +++ b/crates/fake-fxserver/tests/artifacts.rs @@ -241,6 +241,7 @@ async fn seed(db: &Database, servers: &Servers, owner: &Caller, data: &Path) { }], hang_detection: true, hang_timeout_seconds: 360, + stop_hold_seconds: 60, }; servers .change_launch_settings(owner, Servers::DEFAULT, launch, None) @@ -294,6 +295,7 @@ async fn supervise( quit: Duration::from_secs(3), shortened: Duration::from_secs(1), fatal_exit: Duration::from_secs(1), + hold: None, }; settings.recovery = RecoveryPolicy { backoff: vec![Duration::from_millis(500)], diff --git a/crates/fake-fxserver/tests/backups.rs b/crates/fake-fxserver/tests/backups.rs index db58a40b..3ff46f96 100644 --- a/crates/fake-fxserver/tests/backups.rs +++ b/crates/fake-fxserver/tests/backups.rs @@ -219,6 +219,7 @@ fn launch(data: &Path) -> LaunchSettings { extra_arguments: Vec::new(), hang_detection: true, hang_timeout_seconds: 360, + stop_hold_seconds: 60, } } diff --git a/crates/fake-fxserver/tests/changes.rs b/crates/fake-fxserver/tests/changes.rs index 1a80733b..2f4886ea 100644 --- a/crates/fake-fxserver/tests/changes.rs +++ b/crates/fake-fxserver/tests/changes.rs @@ -97,6 +97,7 @@ impl Lab { quit: Duration::from_secs(3), shortened: Duration::from_secs(1), fatal_exit: Duration::from_secs(1), + hold: None, }; }) .await @@ -299,6 +300,7 @@ async fn configure(db: &Database, clock: &Clock, data: &Path) -> (Accounts, Serv extra_arguments: Vec::new(), hang_detection: true, hang_timeout_seconds: 360, + stop_hold_seconds: 60, }; servers .change_launch_settings(&owner, Servers::DEFAULT, launch, None) diff --git a/crates/fake-fxserver/tests/pre_launch.rs b/crates/fake-fxserver/tests/pre_launch.rs index f864aaaa..80ce1726 100644 --- a/crates/fake-fxserver/tests/pre_launch.rs +++ b/crates/fake-fxserver/tests/pre_launch.rs @@ -181,6 +181,7 @@ impl Lab { }], hang_detection: true, hang_timeout_seconds: 360, + stop_hold_seconds: 60, }; let launch = ServerLaunch { build: dir.path().join("build"), @@ -199,6 +200,7 @@ impl Lab { quit: Duration::from_secs(3), shortened: Duration::from_secs(1), fatal_exit: Duration::from_secs(1), + hold: None, }; settings.recovery = RecoveryPolicy { backoff: [100, 200, 300, 400] @@ -739,3 +741,58 @@ async fn a_scheduled_restart_during_the_work_starts_it_over_with_the_launch_conf ); lab.shut_down(false).await; } + +/// The backup before a restart is such work: it reads what the resources saved before they +/// released the stop, since nothing of it begins before FXServer is gone. +#[tokio::test] +async fn the_work_before_a_restart_begins_once_the_resources_that_held_the_stop_released_it() { + let work = Work::new([]); + let mut lab = Lab::tuned(&work, |settings| { + settings.stop.hold = Some(Duration::from_secs(10)); + let launch = settings.launch.as_mut().unwrap(); + for (name, value) in [("fake_holders", "inventory"), ("fake_release_ms", "800")] { + launch.settings.extra_arguments.push(ExtraArgument { + name: name.to_owned(), + value: value.to_owned(), + }); + } + }) + .await; + let cfg = Path::new(&lab.launch.settings.data_path).join("server.cfg"); + fs::write(&cfg, fs::read_to_string(&cfg).unwrap() + "ensure inventory\n").unwrap(); + lab.supervisor.start("test").await.unwrap(); + lab.state(State::Online).await; + let mut status = lab.supervisor.status(); + timeout(WAIT, status.wait_for(|status| status.holders == ["inventory"])) + .await + .expect("the bridge never told who holds the stop") + .unwrap(); + let asked = Instant::now(); + + lab.supervisor.restart_scheduled("observer").await.unwrap(); + lab.state(State::Stopping).await; + lab.state(State::Online).await; + + let seen = work.seen(); + assert_eq!(seen.len(), 2); + assert!( + seen[1].started.duration_since(asked) >= Duration::from_millis(800), + "the work began before the release" + ); + let console = lab.console(); + let position = |needle: &str| { + console + .iter() + .position(|(_, _, text)| text.contains(needle)) + .unwrap_or_else(|| panic!("no {needle:?} in {console:#?}")) + }; + let released = position("inventory released the stop after"); + let quit = position("-> Quitting: scheduled"); + let exited = position("FXServer exited"); + let checked = position("checked for generation 2"); + assert!( + released < quit && quit < exited && exited < checked, + "{console:#?}" + ); + lab.shut_down(true).await; +} diff --git a/crates/fake-fxserver/tests/runtime.rs b/crates/fake-fxserver/tests/runtime.rs index 99e5a2d8..c48e01a9 100644 --- a/crates/fake-fxserver/tests/runtime.rs +++ b/crates/fake-fxserver/tests/runtime.rs @@ -49,7 +49,8 @@ use observer_domain::schedule::{ OneOffRequest, OneOffRestart, RestartSource, ScheduleChange, ScheduleSettings, }; use observer_domain::server::{ - CommandAck, ConsoleLine, Delivery, LINE_MASKED, LineKind, ServerState, ServerStatus, StateCause, + CommandAck, ConsoleLine, Delivery, LINE_MASKED, LineKind, ReleasedHold, ServerState, ServerStatus, + StateCause, }; use observer_domain::server_data::{CfgCheck, FindingKind}; use observer_fxserver::console::plain; @@ -160,6 +161,7 @@ impl Services { quit: Duration::from_secs(3), shortened: Duration::from_secs(1), fatal_exit: Duration::from_secs(1), + hold: None, }; settings.recovery = RecoveryPolicy { backoff: vec![Duration::from_millis(100)], @@ -259,6 +261,7 @@ impl Observer { .collect(), hang_detection: true, hang_timeout_seconds: 360, + stop_hold_seconds: 60, }; services .servers @@ -935,7 +938,8 @@ async fn a_one_off_warns_the_bridge_then_restarts_on_schedule() { .find(|line| line.0 == notice) .unwrap(); assert!( - plain(&shutting_down.5).contains(r#""by":"ada","delayMs":300,"reason":"scheduled""#), + plain(&shutting_down.5) + .contains(r#""by":"ada","delayMs":300,"maxDelayMs":60000,"reason":"scheduled""#), "{shutting_down:?}" ); assert!(restarted.started_at.is_some()); @@ -3350,3 +3354,134 @@ async fn a_server_without_onesync_has_no_entities_to_list() { assert_eq!((told.run, told.listed, told.counts), (None, 0, None)); assert_eq!(page.items, []); } + +impl Observer { + /// An Observer whose server starts `inventory`, a resource that holds each stop and never + /// releases it, online once Observer has heard of it. The owner set the wait to its least. + async fn held_by_inventory() -> Self { + let mut arguments = FAKE.to_vec(); + arguments.push(("fake_holders", "inventory")); + let observer = Self::launched(false, Duration::from_millis(50), &arguments).await; + let data = observer.dir.path().join("server-data"); + let folder = data.join("resources/inventory"); + fs::create_dir_all(&folder).unwrap(); + fs::write( + folder.join("fxmanifest.lua"), + "fx_version 'cerulean'\ngame 'gta5'\n", + ) + .unwrap(); + let cfg = data.join("server.cfg"); + fs::write(&cfg, fs::read_to_string(&cfg).unwrap() + "ensure inventory\n").unwrap(); + let stored = observer + .servers + .launch_settings(Servers::DEFAULT) + .await + .unwrap() + .unwrap(); + let settings = LaunchSettings { + stop_hold_seconds: 5, + ..stored.settings + }; + observer + .servers + .change_launch_settings(&observer.owner, Servers::DEFAULT, settings, Some(stored.version)) + .await + .unwrap(); + observer.supervision.start_server(&observer.owner).await.unwrap(); + observer + .until(|status| status.state == ServerState::Online && status.stop_holders == ["inventory"]) + .await; + observer + } +} + +#[tokio::test] +async fn a_stop_that_went_on_without_its_resources_is_audited_with_their_names() { + let mut observer = Observer::held_by_inventory().await; + + observer + .supervision + .restart_server(&observer.owner) + .await + .unwrap(); + + let held = observer + .until(|status| { + status + .stop + .as_ref() + .is_some_and(|stop| stop.holding == ["inventory"]) + }) + .await; + let stop = held.stop.unwrap(); + assert_eq!(held.state, ServerState::Stopping); + assert_eq!( + stop.since.duration_until(stop.limit_at), + SignedDuration::from_secs(5) + ); + assert_eq!(stop.released, Vec::::new()); + observer + .until(|status| status.generation == 2 && status.state == ServerState::Online) + .await; + assert_eq!(observer.supervision.status().borrow().stop, None); + let expired = observer.audited(AuditAction::ServerStopHoldExpired).await; + assert_eq!(expired.len(), 1); + assert_eq!( + (expired[0].actor_kind, expired[0].outcome), + (ActorKind::System, Outcome::Failure) + ); + assert_eq!(expired[0].target.as_deref(), Some("default")); + assert_eq!( + expired[0].details, + json!({ "resources": ["inventory"], "reason": "limit", "waitedSeconds": 5 }) + ); + assert_eq!( + observer.audited(AuditAction::ServerStopHoldSkipped).await, + Vec::::new() + ); + let told = observer.console_until("observer:shuttingDown").await; + assert!(plain(&told.5).contains(r#""maxDelayMs":5000"#), "{told:?}"); + observer.stop_observer().await; +} + +#[tokio::test] +async fn whoever_skips_the_wait_is_audited_with_the_resources_left_behind() { + let mut observer = Observer::held_by_inventory().await; + let before = observer.supervision.stop_now(&observer.owner).await; + observer.supervision.stop_server(&observer.owner).await.unwrap(); + observer + .until(|status| { + status + .stop + .as_ref() + .is_some_and(|stop| stop.holding == ["inventory"]) + }) + .await; + + observer.supervision.stop_now(&observer.owner).await.unwrap(); + let again = observer.supervision.stop_now(&observer.owner).await; + + observer.state(ServerState::Stopped).await; + for refused in [&before, &again] { + assert!( + matches!(refused, Err(Error::Refused(error)) if error.code == ErrorCode::StopNotHeld), + "{refused:?}" + ); + } + let skipped = observer.audited(AuditAction::ServerStopHoldSkipped).await; + assert_eq!(skipped.len(), 1); + assert_eq!( + (skipped[0].actor_kind, skipped[0].actor_name.as_deref()), + (ActorKind::User, Some("ada")) + ); + assert_eq!(skipped[0].target.as_deref(), Some("default")); + assert_eq!(skipped[0].details, json!({ "resources": ["inventory"] })); + assert_eq!( + observer.audited(AuditAction::ServerStopHoldExpired).await, + Vec::::new() + ); + observer + .console_until("ada had FXServer quit without waiting for inventory") + .await; + observer.stop_observer().await; +} diff --git a/crates/fake-fxserver/tests/supervisor.rs b/crates/fake-fxserver/tests/supervisor.rs index 43b1982b..9b6ada7d 100644 --- a/crates/fake-fxserver/tests/supervisor.rs +++ b/crates/fake-fxserver/tests/supervisor.rs @@ -31,8 +31,8 @@ use observer_fxserver::perf::Thread; use observer_fxserver::recovery::RecoveryPolicy; use observer_fxserver::stdin::{StdinError, UserCommand}; use observer_fxserver::supervisor::{ - Cause, ControlError, Counting, Event, EventKind, Hooked, ProcessChange, START_EXTENSION, Settings, - StartStatus, State, StopTimings, Supervisor, TreeEvent, + Cause, ControlError, Counting, Event, EventKind, HoldEnd, Hooked, ProcessChange, START_EXTENSION, + Settings, StartStatus, State, StopStatus, StopTimings, Supervisor, TreeEvent, }; use observer_platform::{ProcessInfo, Protocol, Socket, SocketState}; use tempfile::TempDir; @@ -103,6 +103,7 @@ impl Lab { extra_arguments, hang_detection: true, hang_timeout_seconds: 360, + stop_hold_seconds: 60, }; let launch = ServerLaunch { build: dir.path().join("build"), @@ -121,6 +122,7 @@ impl Lab { quit: Duration::from_secs(3), shortened: Duration::from_secs(1), fatal_exit: Duration::from_secs(1), + hold: Some(Duration::from_secs(2)), }; settings.recovery = RecoveryPolicy { backoff: [100, 200, 300, 400] @@ -1437,7 +1439,11 @@ async fn the_shortened_stop_sends_event_and_quit_at_once_and_kills_within_its_wi closing.elapsed() ); let notice = lab.console_until("observer:shuttingDown").await; - assert!(lab.console()[notice].2.contains(r#""delayMs":0"#)); + let told = &lab.console()[notice].2; + assert!( + told.contains(r#""delayMs":0"#) && told.contains(r#""maxDelayMs":0"#), + "{told}" + ); assert!( lab.console() .iter() @@ -2120,3 +2126,632 @@ async fn a_build_whose_scheduler_cannot_be_hooked_starts_all_the_same() { lab.console_until("Debug counts nothing in this start").await; lab.shut_down(false).await; } + +/// A lab whose cfg starts `resources`, each of which asks the bridge to hold the stop, online +/// once Observer has heard of them. `cfg` adds lines to the cfg, such as a release time. +async fn holding(resources: &[&str], extra: &[(&str, &str)], cfg: &[&str]) -> Lab { + holding_tuned(resources, extra, cfg, |_| {}).await +} + +async fn holding_tuned( + resources: &[&str], + extra: &[(&str, &str)], + cfg: &[&str], + tune: impl FnOnce(&mut Settings), +) -> Lab { + let names = resources.join(","); + let mut convars = extra.to_vec(); + convars.push(("fake_holders", &names)); + let mut lab = Lab::tuned(&convars, tune).await; + extend_cfg(&lab, resources, cfg); + lab.supervisor.start("test").await.unwrap(); + lab.state(State::Online).await; + lab.holders(resources).await; + lab +} + +fn stop_held(kind: &EventKind) -> bool { + matches!(kind, EventKind::StopHeld { .. }) +} + +impl Lab { + /// Waits until the bridge told Observer that exactly `resources` hold each stop. + async fn holders(&self, resources: &[&str]) { + let mut status = self.supervisor.status(); + let told = timeout(WAIT, async { + loop { + if status.borrow_and_update().holders == resources { + return; + } + status.changed().await.unwrap(); + } + }) + .await; + assert!( + told.is_ok(), + "the holders never came to {resources:?}: {:?}", + self.supervisor.status().borrow().holders + ); + } + + /// The stop under way once it is as `wanted`, as the status publishes it. + async fn stop_until(&self, wanted: impl Fn(&StopStatus) -> bool) -> StopStatus { + let mut status = self.supervisor.status(); + let found = timeout(WAIT, async { + loop { + let stop = status.borrow_and_update().stop.clone(); + if let Some(stop) = stop.filter(&wanted) { + return stop; + } + status.changed().await.unwrap(); + } + }) + .await; + found.unwrap_or_else(|_| { + panic!( + "the stop never came to that: {:#?}", + self.supervisor.status().borrow().stop + ) + }) + } + + /// The payloads of every `observer:shuttingDown` the bridge raised, in order. + fn told_of_the_stop(&self) -> Vec { + self.console() + .iter() + .filter_map(|(_, _, text)| { + serde_json::from_str(text.split_once("observer:shuttingDown ")?.1).ok() + }) + .collect() + } + + fn notes(&self) -> Vec { + self.console() + .into_iter() + .filter(|(kind, actor, _)| *kind == LineKind::Observer && actor.as_deref() == Some("supervisor")) + .map(|(_, _, text)| text) + .collect() + } +} + +#[tokio::test] +async fn a_stop_waits_for_the_resource_that_holds_it_and_quits_once_it_released() { + let mut lab = holding(&["inventory"], &[("fake_release_ms", "900")], &[]).await; + let asked = Instant::now(); + + lab.supervisor.stop("test").await.unwrap(); + + let held = lab.stop_until(|stop| stop.holding == ["inventory"]).await; + assert_eq!(held.limit_at_ms - held.since_ms, 2000); + assert_eq!(held.released, Vec::<(String, u64)>::new()); + let ended = lab.event(stop_held).await; + let quit = lab.console_until("-> Quitting: stop").await; + assert!( + asked.elapsed() >= Duration::from_millis(900), + "quit before the release" + ); + assert!( + matches!(&ended, EventKind::StopHeld { unreleased, end: HoldEnd::Released, .. } if unreleased.is_empty()), + "{ended:?}" + ); + let told = lab.told_of_the_stop(); + assert_eq!(told.len(), 1, "{told:?}"); + assert_eq!( + (&told[0]["delayMs"], &told[0]["maxDelayMs"]), + (&300.into(), &2000.into()) + ); + let console = lab.console(); + let waiting = lab + .console_index("waiting for inventory to release the stop, 2 s at most") + .unwrap(); + let released = lab.console_index("inventory released the stop after").unwrap(); + assert!(waiting < released && released < quit, "{console:#?}"); + lab.state(State::Stopped).await; + assert_eq!(lab.supervisor.status().borrow().stop, None); + lab.shut_down(false).await; +} + +#[tokio::test] +async fn a_stop_no_resource_holds_quits_after_its_notice_as_it_always_did() { + let mut lab = Lab::online(&[]).await; + + lab.supervisor.stop("test").await.unwrap(); + + lab.state(State::Stopped).await; + assert!(!lab.seen.iter().any(stop_held), "{:#?}", lab.seen); + assert!( + !lab.notes().iter().any(|note| note.contains("the stop")), + "{:#?}", + lab.notes() + ); + let told = lab.told_of_the_stop(); + assert_eq!( + (&told[0]["delayMs"], &told[0]["maxDelayMs"]), + (&300.into(), &2000.into()) + ); + lab.shut_down(false).await; +} + +#[tokio::test] +async fn a_resource_that_never_releases_is_named_once_the_limit_has_passed() { + let mut lab = holding(&["garage", "inventory"], &[], &["set fake_release_ms:garage 100"]).await; + let asked = Instant::now(); + + lab.supervisor.restart("test").await.unwrap(); + + let held = lab + .stop_until(|stop| stop.holding == ["inventory"] && stop.released.len() == 1) + .await; + assert_eq!(held.released[0].0, "garage"); + let ended = lab.event(stop_held).await; + assert!(asked.elapsed() >= Duration::from_secs(2), "quit before the limit"); + let EventKind::StopHeld { + unreleased, + waited_ms, + end, + } = ended + else { + unreachable!() + }; + assert_eq!((unreleased, end), (vec!["inventory".to_owned()], HoldEnd::Limit)); + assert!(waited_ms >= 2000, "{waited_ms}"); + let named = lab + .console_until("inventory did not release the stop within 2 s; FXServer quits anyway") + .await; + let quit = lab.console_until("-> Quitting: restart").await; + assert!(named < quit); + // The restart goes on, and the new run's resources hold its stops in their turn. + lab.state(State::Online).await; + assert_eq!(lab.generation(), 2); + lab.holders(&["garage", "inventory"]).await; + lab.shut_down(true).await; +} + +#[tokio::test] +async fn a_scheduled_restart_and_one_someone_planned_wait_for_the_resources_that_hold_the_stop() { + for by in ["observer", "ada"] { + let mut lab = holding(&["inventory"], &[("fake_release_ms", "700")], &[]).await; + + lab.supervisor.restart_scheduled(by).await.unwrap(); + + lab.stop_until(|stop| stop.holding == ["inventory"]).await; + let ended = lab.event(stop_held).await; + assert!( + matches!( + ended, + EventKind::StopHeld { + end: HoldEnd::Released, + .. + } + ), + "{ended:?}" + ); + let released = lab.console_until("inventory released the stop after").await; + let quit = lab.console_until("-> Quitting: scheduled").await; + assert!(released < quit, "{by}"); + assert_eq!( + lab.state(State::Starting).await, + Cause::Scheduled { by: by.to_owned() } + ); + lab.state(State::Online).await; + assert_eq!(lab.told_of_the_stop()[0]["reason"], "scheduled"); + lab.shut_down(true).await; + } +} + +#[tokio::test] +async fn observer_stopping_waits_for_the_resources_that_hold_the_stop() { + // By itself, as for an update installed now, and in the place of a scheduled restart. + for scheduled in [false, true] { + let mut lab = holding(&["inventory"], &[("fake_release_ms", "700")], &[]).await; + let asked = Instant::now(); + + if scheduled { + lab.supervisor.shutdown_scheduled().await; + } else { + lab.supervisor.shutdown(false).await; + } + timeout(WAIT, lab.task.take().unwrap()) + .await + .expect("the supervisor did not stop") + .unwrap(); + + assert!( + asked.elapsed() >= Duration::from_millis(700), + "quit before the release" + ); + let reason = if scheduled { "scheduled" } else { "shutdown" }; + let released = lab.console_index("inventory released the stop after").unwrap(); + let quit = lab.console_index(&format!("-> Quitting: {reason}")).unwrap(); + assert!(released < quit); + let told = lab.told_of_the_stop(); + assert_eq!( + (&told[0]["reason"], &told[0]["maxDelayMs"]), + (&reason.into(), &2000.into()) + ); + } +} + +#[tokio::test] +async fn a_new_launch_applied_by_a_restart_waits_for_the_resources_that_hold_the_stop() { + let mut lab = holding(&["inventory"], &[("fake_release_ms", "700")], &[]).await; + let mut launch = lab.launch.clone(); + launch.settings.extra_arguments.push(ExtraArgument { + name: "fake_build".to_owned(), + value: "36000".to_owned(), + }); + + lab.supervisor.configure(launch).await; + lab.supervisor.restart("test").await.unwrap(); + + let released = lab.console_until("inventory released the stop after").await; + let quit = lab.console_until("-> Quitting: restart").await; + assert!(released < quit); + lab.state(State::Online).await; + let mut status = lab.supervisor.status(); + timeout(WAIT, status.wait_for(|status| status.build == Some(36_000))) + .await + .expect("the restart did not take the new launch") + .unwrap(); + lab.shut_down(true).await; +} + +#[tokio::test] +async fn a_crash_or_a_hang_asks_no_resource_and_waits_for_none() { + let mut crashed = holding(&["inventory"], &[], &[]).await; + let mut hung = holding(&["inventory"], &[], &[]).await; + + crashed.type_command("fake_crash", "test").await; + hung.type_command("fake_hang", "test").await; + + assert!(matches!( + crashed.state(State::Crashed).await, + Cause::Exited { .. } + )); + assert!(matches!(hung.state(State::Hung).await, Cause::Hang { .. })); + hung.state(State::Crashed).await; + for lab in [&crashed, &hung] { + assert_eq!(lab.told_of_the_stop(), Vec::::new()); + assert!(!lab.seen.iter().any(stop_held), "{:#?}", lab.seen); + assert!(!lab.notes().iter().any(|note| note.contains("the stop"))); + } + // The run that follows holds its own stops. + crashed.state(State::Online).await; + crashed.holders(&["inventory"]).await; + crashed.shut_down(true).await; + hung.shut_down(true).await; +} + +#[tokio::test] +async fn a_closing_console_waits_for_no_one_and_says_who_it_left() { + let mut lab = holding(&["inventory"], &[], &[]).await; + let closing = Instant::now(); + + lab.shut_down(true).await; + + assert!( + closing.elapsed() < Duration::from_secs(2), + "took {:?}", + closing.elapsed() + ); + let told = lab.told_of_the_stop(); + assert_eq!( + (&told[0]["delayMs"], &told[0]["maxDelayMs"]), + (&0.into(), &0.into()) + ); + lab.console_index("the console is closing: no time left to wait for inventory") + .unwrap(); + let mut left = None; + while let Ok(event) = lab.events.try_recv() { + if stop_held(&event.kind) { + left = Some(event.kind); + } + } + assert_eq!( + left, + Some(EventKind::StopHeld { + unreleased: vec!["inventory".to_owned()], + waited_ms: 0, + end: HoldEnd::Shortened, + }) + ); +} + +#[tokio::test] +async fn a_console_closed_during_the_wait_cuts_it_short() { + let mut lab = holding_tuned(&["inventory"], &[], &[], |settings| { + settings.stop.hold = Some(Duration::from_secs(60)); + }) + .await; + lab.supervisor.stop("test").await.unwrap(); + lab.stop_until(|stop| stop.holding == ["inventory"]).await; + let closing = Instant::now(); + + lab.shut_down(true).await; + + assert!( + closing.elapsed() < Duration::from_secs(5), + "took {:?}", + closing.elapsed() + ); + let note = lab + .console_index("the console is closing: no time left to wait for inventory") + .unwrap(); + let quit = lab.console_index("-> Quitting: stop").unwrap(); + assert!(note < quit); + let mut ends = Vec::new(); + while let Ok(event) = lab.events.try_recv() { + if let EventKind::StopHeld { end, unreleased, .. } = event.kind { + ends.push((end, unreleased)); + } + } + assert_eq!(ends, [(HoldEnd::Shortened, vec!["inventory".to_owned()])]); +} + +#[tokio::test] +async fn a_server_whose_main_loop_is_stuck_is_waited_for_until_the_limit_then_killed() { + let mut lab = holding(&["inventory"], &[("fake_release_ms", "100")], &[]).await; + lab.type_command("fake_hang", "test").await; + let asked = Instant::now(); + + lab.supervisor.stop("test").await.unwrap(); + + let ended = lab.event(stop_held).await; + assert!( + matches!(&ended, EventKind::StopHeld { unreleased, end: HoldEnd::Limit, .. } if unreleased == &["inventory"]), + "{ended:?}" + ); + assert!( + matches!(lab.event(exited).await, EventKind::Exited { expected: true, code, .. } if code == KILLED) + ); + // The limit, then what `quit` gets before the kill. + assert!( + asked.elapsed() >= Duration::from_secs(5), + "took {:?}", + asked.elapsed() + ); + assert!( + lab.told_of_the_stop().is_empty(), + "the stuck loop raised the event" + ); + lab.state(State::Stopped).await; + lab.shut_down(false).await; +} + +#[tokio::test] +async fn a_resource_that_stops_or_restarts_holds_the_stop_only_while_it_runs() { + let mut lab = holding(&["garage", "inventory"], &[], &[]).await; + + lab.type_command("stop garage", "test").await; + lab.holders(&["inventory"]).await; + lab.type_command("ensure garage", "test").await; + lab.holders(&["garage", "inventory"]).await; + lab.type_command("restart garage", "test").await; + lab.console_until("Stopping resource garage").await; + lab.holders(&["garage", "inventory"]).await; + + lab.supervisor.stop("test").await.unwrap(); + lab.stop_until(|stop| stop.holding == ["garage", "inventory"]) + .await; + lab.type_command("stop garage", "test").await; + let held = lab.stop_until(|stop| stop.holding == ["inventory"]).await; + lab.type_command("fake_release inventory", "test").await; + + let ended = lab.event(stop_held).await; + assert!( + matches!(&ended, EventKind::StopHeld { unreleased, end: HoldEnd::Released, .. } if unreleased.is_empty()), + "{ended:?}" + ); + assert!( + held.released.is_empty(), + "a stopped resource released nothing: {held:?}" + ); + lab.console_index("garage stopped: the stop no longer waits for it") + .unwrap(); + lab.console_until("inventory released the stop after").await; + lab.state(State::Stopped).await; + lab.shut_down(false).await; +} + +#[tokio::test] +async fn a_bridge_started_again_holds_nothing_of_what_the_one_before_held() { + let mut lab = holding(&["inventory"], &[], &[]).await; + let bridge = lab.bridge(); + + lab.type_command(&format!("ensure {bridge}"), "test").await; + + lab.holders(&[]).await; + lab.supervisor.stop("test").await.unwrap(); + lab.state(State::Stopped).await; + assert!(!lab.seen.iter().any(stop_held), "{:#?}", lab.seen); + lab.shut_down(false).await; +} + +#[tokio::test] +async fn a_stop_that_overtakes_a_restart_keeps_its_wait_and_its_limit() { + let mut lab = holding_tuned(&["inventory"], &[], &[], |settings| { + settings.stop.hold = Some(Duration::from_secs(30)); + }) + .await; + lab.supervisor.restart("grace").await.unwrap(); + lab.state(State::Stopping).await; + let first = lab.stop_until(|stop| stop.holding == ["inventory"]).await; + + lab.supervisor.stop("ada").await.unwrap(); + + assert_eq!( + lab.state(State::Stopping).await, + Cause::Requested { by: "ada".to_owned() } + ); + let again = lab.stop_until(|stop| stop.holding == ["inventory"]).await; + assert_eq!( + (again.since_ms, again.limit_at_ms), + (first.since_ms, first.limit_at_ms) + ); + lab.console_until(r#""reason":"stop""#).await; + lab.type_command("fake_release inventory", "test").await; + lab.console_until("-> Quitting: stop").await; + lab.state(State::Stopped).await; + lab.none_within(Duration::from_secs(1), starting).await; + let told = lab.told_of_the_stop(); + assert_eq!(told.len(), 2, "{told:?}"); + assert_eq!( + (&told[0]["reason"], &told[0]["maxDelayMs"]), + (&"restart".into(), &30_000.into()) + ); + let left = told[1]["maxDelayMs"].as_u64().unwrap(); + assert!( + told[1]["reason"] == "stop" && left < 30_000 && left > 0, + "{:?}", + told[1] + ); + assert!(told[1]["delayMs"].as_u64().unwrap() <= 300); + let ends: Vec<&EventKind> = lab.seen.iter().filter(|kind| stop_held(kind)).collect(); + assert_eq!(ends.len(), 1, "one stop, one wait: {ends:?}"); + lab.shut_down(false).await; +} + +#[tokio::test] +async fn whoever_controls_the_server_can_have_it_quit_without_waiting() { + let mut lab = holding_tuned(&["garage", "inventory"], &[], &[], |settings| { + settings.stop.hold = Some(Duration::from_secs(60)); + }) + .await; + let while_running = lab.supervisor.quit_now("ada").await; + lab.supervisor.stop("test").await.unwrap(); + lab.stop_until(|stop| stop.holding == ["garage", "inventory"]) + .await; + lab.type_command("fake_release garage", "test").await; + lab.stop_until(|stop| stop.holding == ["inventory"]).await; + + let skipped = lab.supervisor.quit_now("ada").await; + let again = lab.supervisor.quit_now("ada").await; + + assert_eq!(while_running, Err(ControlError::NotHeld)); + assert_eq!(skipped, Ok(vec!["inventory".to_owned()])); + assert_eq!(again, Err(ControlError::NotHeld)); + let ended = lab.event(stop_held).await; + assert!( + matches!( + &ended, + EventKind::StopHeld { unreleased, end: HoldEnd::Skipped { by }, .. } + if unreleased == &["inventory"] && by == "ada" + ), + "{ended:?}" + ); + let note = lab + .console_until("ada had FXServer quit without waiting for inventory") + .await; + let quit = lab.console_until("-> Quitting: stop").await; + assert!(note < quit); + lab.state(State::Stopped).await; + assert_eq!(lab.supervisor.status().borrow().stop, None); + lab.shut_down(false).await; +} + +#[tokio::test] +async fn a_stop_nobody_holds_has_no_wait_to_skip() { + let mut lab = Lab::online(&[]).await; + lab.supervisor.stop("test").await.unwrap(); + + let skipped = lab.supervisor.quit_now("ada").await; + + assert_eq!(skipped, Err(ControlError::NotHeld)); + lab.state(State::Stopped).await; + lab.shut_down(false).await; +} + +#[tokio::test] +async fn a_resource_that_asks_during_the_notice_is_waited_for_too() { + let mut lab = Lab::tuned(&[], |settings| { + settings.stop.notice = Duration::from_secs(3); + settings.stop.hold = Some(Duration::from_secs(60)); + }) + .await; + extend_cfg(&lab, &["garage"], &[]); + lab.supervisor.start("test").await.unwrap(); + lab.state(State::Online).await; + lab.holders(&[]).await; + + lab.supervisor.stop("test").await.unwrap(); + lab.console_until("observer:shuttingDown").await; + lab.type_command("fake_hold garage", "test").await; + + lab.stop_until(|stop| stop.holding == ["garage"]).await; + lab.console_until("garage holds the stop too").await; + lab.none_within(Duration::from_secs(4), exited).await; + lab.type_command("fake_release garage", "test").await; + let ended = lab.event(stop_held).await; + assert!( + matches!( + ended, + EventKind::StopHeld { + end: HoldEnd::Released, + .. + } + ), + "{ended:?}" + ); + lab.state(State::Stopped).await; + lab.shut_down(false).await; +} + +#[tokio::test] +async fn a_quit_typed_during_the_wait_ends_it_there() { + let mut lab = holding_tuned(&["inventory"], &[], &[], |settings| { + settings.stop.hold = Some(Duration::from_secs(60)); + }) + .await; + lab.supervisor.restart("grace").await.unwrap(); + lab.stop_until(|stop| stop.holding == ["inventory"]).await; + + lab.type_command("quit", "alice").await; + + let ended = lab.event(stop_held).await; + assert!( + matches!(&ended, EventKind::StopHeld { end: HoldEnd::Skipped { by }, .. } if by == "alice"), + "{ended:?}" + ); + // The restart it interrupted still follows. + lab.state(State::Online).await; + assert_eq!(lab.generation(), 2); + lab.shut_down(true).await; +} + +#[tokio::test] +async fn the_owners_limit_bounds_the_wait_and_a_change_reaches_the_next_stop() { + let mut lab = holding_tuned(&["inventory"], &[], &[], |settings| { + settings.stop.hold = None; + }) + .await; + let mut launch = lab.launch.clone(); + launch.settings.extra_arguments.push(ExtraArgument { + name: "fake_holders".to_owned(), + value: "inventory".to_owned(), + }); + launch.settings.stop_hold_seconds = 5; + + lab.supervisor.configure(launch).await; + let asked = Instant::now(); + lab.supervisor.stop("test").await.unwrap(); + + let held = lab.stop_until(|stop| stop.holding == ["inventory"]).await; + assert_eq!(held.limit_at_ms - held.since_ms, 5000); + let ended = lab.event(stop_held).await; + assert!( + matches!( + ended, + EventKind::StopHeld { + end: HoldEnd::Limit, + .. + } + ), + "{ended:?}" + ); + assert!(asked.elapsed() >= Duration::from_secs(5)); + assert_eq!(lab.told_of_the_stop()[0]["maxDelayMs"], 5000); + lab.console_until("inventory did not release the stop within 5 s; FXServer quits anyway") + .await; + lab.state(State::Stopped).await; + lab.shut_down(false).await; +} diff --git a/crates/observer-app/src/changes/views.rs b/crates/observer-app/src/changes/views.rs index 0acc481e..e71c6bf1 100644 --- a/crates/observer-app/src/changes/views.rs +++ b/crates/observer-app/src/changes/views.rs @@ -59,9 +59,10 @@ const WRITES: [AuditAction; 3] = [ /// data folder. const SHOWN_SETTINGS: [&str; 3] = ["onesync", "autoStart", "txadminEvents"]; const OWNER_SETTINGS: [&str; 2] = ["cfgFile", "dataPath"]; -/// Launch settings a snapshot leaves out, as `launch_record` does: they apply at once to the -/// running server rather than at a start, so they are no part of what a start ran with. -const UNCOMPARED_SETTINGS: [&str; 2] = ["hangDetection", "hangTimeoutSeconds"]; +/// Launch settings a snapshot leaves out, as `launch_record` does: they apply to the running +/// server, at once or at its next stop, rather than at a start, so they are no part of what a start +/// ran with. +const UNCOMPARED_SETTINGS: [&str; 3] = ["hangDetection", "hangTimeoutSeconds", "stopHoldSeconds"]; /// The later side of a comparison. #[derive(Debug, Clone, Copy, PartialEq, Eq)] @@ -1576,6 +1577,9 @@ mod tests { &json!({ "hangDetection": switch, "hangTimeoutSeconds": delay }) )); assert!(!launch(&json!({ "hangDetection": switch, "setup": true }))); + assert!(!launch( + &json!({ "stopHoldSeconds": { "before": 60, "after": 120 } }) + )); assert!(launch( &json!({ "onesync": { "before": "on", "after": "legacy" }, "hangDetection": switch }) )); diff --git a/crates/observer-app/src/diagnostics/crashes.rs b/crates/observer-app/src/diagnostics/crashes.rs index 0910122f..6e53e096 100644 --- a/crates/observer-app/src/diagnostics/crashes.rs +++ b/crates/observer-app/src/diagnostics/crashes.rs @@ -280,6 +280,7 @@ mod tests { extra_arguments: Vec::new(), hang_detection: true, hang_timeout_seconds: 360, + stop_hold_seconds: 60, }), }, ) diff --git a/crates/observer-app/src/diagnostics/tests.rs b/crates/observer-app/src/diagnostics/tests.rs index 68e37ef8..938fe5bc 100644 --- a/crates/observer-app/src/diagnostics/tests.rs +++ b/crates/observer-app/src/diagnostics/tests.rs @@ -104,6 +104,7 @@ impl Lab { extra_arguments: Vec::new(), hang_detection: true, hang_timeout_seconds: 360, + stop_hold_seconds: 60, }), }, ) @@ -587,6 +588,7 @@ async fn the_processes_an_earlier_observer_left_running_end_when_the_next_one_st extra_arguments: Vec::new(), hang_detection: true, hang_timeout_seconds: 360, + stop_hold_seconds: 60, }), }, }) diff --git a/crates/observer-app/src/metrics/runs.rs b/crates/observer-app/src/metrics/runs.rs index 3440f7e1..5cc31aad 100644 --- a/crates/observer-app/src/metrics/runs.rs +++ b/crates/observer-app/src/metrics/runs.rs @@ -217,6 +217,7 @@ mod tests { extra_arguments: Vec::new(), hang_detection: true, hang_timeout_seconds: 360, + stop_hold_seconds: 60, }), })), Some(Change::Spawned { at_ms }) @@ -295,6 +296,7 @@ mod tests { extra_arguments: Vec::new(), hang_detection: true, hang_timeout_seconds: 360, + stop_hold_seconds: 60, }), }; let events = [ diff --git a/crates/observer-app/src/metrics/sampler/tests.rs b/crates/observer-app/src/metrics/sampler/tests.rs index 52326132..9f3101bb 100644 --- a/crates/observer-app/src/metrics/sampler/tests.rs +++ b/crates/observer-app/src/metrics/sampler/tests.rs @@ -961,6 +961,7 @@ fn hitches_and_barks_are_counted_per_slot_while_a_run_exists() { extra_arguments: Vec::new(), hang_detection: true, hang_timeout_seconds: 360, + stop_hold_seconds: 60, }), }, ), diff --git a/crates/observer-app/src/players/tests.rs b/crates/observer-app/src/players/tests.rs index 1607215e..f15f48b5 100644 --- a/crates/observer-app/src/players/tests.rs +++ b/crates/observer-app/src/players/tests.rs @@ -318,6 +318,7 @@ fn a_run_is_written_with_its_spawn_so_a_start_stopped_or_restarted_before_it_wri extra_arguments: Vec::new(), hang_detection: true, hang_timeout_seconds: 360, + stop_hold_seconds: 60, }), }, }; diff --git a/crates/observer-app/src/servers.rs b/crates/observer-app/src/servers.rs index aff78057..cb12840b 100644 --- a/crates/observer-app/src/servers.rs +++ b/crates/observer-app/src/servers.rs @@ -130,12 +130,13 @@ pub(crate) fn follow_rules(settings: &LaunchSettings) -> Result<(), Error> { /// The settings whose values anyone reading the log may see. Only the owner reads the others, /// and an argument may well hold a token: the log only says they changed. -const SHOWN: [&str; 5] = [ +const SHOWN: [&str; 6] = [ "onesync", "autoStart", "txadminEvents", "hangDetection", "hangTimeoutSeconds", + "stopHoldSeconds", ]; /// Each setting that differs: its value before and after for the shown ones, `true` for a hidden diff --git a/crates/observer-app/src/supervision.rs b/crates/observer-app/src/supervision.rs index 395ebdaa..ca7580c8 100644 --- a/crates/observer-app/src/supervision.rs +++ b/crates/observer-app/src/supervision.rs @@ -24,8 +24,8 @@ use observer_domain::schedule::RestartSource; use observer_domain::server::{ AssetMemory, CommandAck, CommandRefusal, ConsoleLine, ConsoleSnapshot, Delivery, HangCause, HealthProblem, HeavyAsset, LINE_MASKED, LINE_NO_EOL, LINE_TRUNCATED, LaunchReadiness, LineKind, LogFile, - MissingFile, PlayerCount, ServerState, ServerStatus, SlowResource, StartCommand, StartProgress, - StartWarnings, StartedResource, StateCause, + MissingFile, PlayerCount, ReleasedHold, ServerState, ServerStatus, SlowResource, StartCommand, + StartProgress, StartWarnings, StartedResource, StateCause, StopProgress, }; use observer_fxserver::bridge::BridgeEvent; use observer_fxserver::console::{self as fx_console, ConsoleHub, ConsoleLog, LineFlags}; @@ -34,7 +34,7 @@ use observer_fxserver::launch::ServerLaunch; use observer_fxserver::start as fx_start; use observer_fxserver::stdin::{self, StdinError, UserCommand}; use observer_fxserver::supervisor::{ - self as fx, Cause, ControlError, EventKind, Settings, State, Supervisor, + self as fx, Cause, ControlError, EventKind, HoldEnd, Settings, State, Supervisor, }; use observer_store::Database; use observer_store::artifacts::{self as stored_artifacts, ArtifactState}; @@ -467,6 +467,22 @@ impl Supervision { extended.map_err(control_error) } + /// Has the stop under way go on without the resources that still hold it: FXServer quits + /// once the notice every stop gives has passed. The audit log keeps who did, and which + /// resources had not released the stop. + pub async fn stop_now(&self, caller: &Caller) -> Result<(), Error> { + let unreleased = self + .inner + .supervisor + .quit_now(&caller.username) + .await + .map_err(control_error)?; + let record = Record::by(caller, AuditAction::ServerStopHoldSkipped) + .target(Servers::DEFAULT) + .details(json!({ "resources": unreleased })); + self.audit(record).await + } + /// Stops FXServer gracefully and starts it again with the stored settings, which must be fit /// to start before anything stops. pub async fn restart_server(&self, caller: &Caller) -> Result<(), Error> { @@ -837,8 +853,9 @@ impl Supervision { /// Keeps the panel's status in step with the supervisor's, the cause of its last change of state /// and the stored launch settings, which it hands to the supervisor as they change. A tripped -/// crash loop breaker goes to the audit log: the server stays down until someone acts. What the -/// cfg of a run that starts does against Observer goes to the console. +/// crash loop breaker goes to the audit log: the server stays down until someone acts. So does a +/// stop that went on without the resources that held it. What the cfg of a run that starts does +/// against Observer goes to the console. #[expect( clippy::too_many_arguments, reason = "what the follower works with, each handed over once as it starts" @@ -905,6 +922,27 @@ async fn follow( .ok() .and_then(|at| at.checked_add(delay).ok()); } + EventKind::StopHeld { unreleased, waited_ms, end } => { + // Whoever skipped the wait is audited as they ask, under their own name. + let reason = match end { + HoldEnd::Limit => "limit", + HoldEnd::Shortened => "consoleClosed", + HoldEnd::Released | HoldEnd::Skipped { .. } => continue, + }; + let record = Record::operator(ActorKind::System, AuditAction::ServerStopHoldExpired) + .target(Servers::DEFAULT) + .outcome(Outcome::Failure) + .details(json!({ + "resources": unreleased, + "reason": reason, + "waitedSeconds": waited_ms / 1000, + })); + let now = clock.now(); + if let Err(error) = db.write(move |tx| record.write(tx, now)).await { + warn!(%error, "cannot audit the stop its resources held past their limit"); + } + continue; + } _ => continue, }, // The status itself is still exact; only a cause may be stale until the next change. @@ -1004,6 +1042,20 @@ fn server_status( extension_minutes: EXTENSION_MINUTES, } }), + stop_holders: status.holders.clone(), + stop: status.stop.as_ref().map(|stop| StopProgress { + since: at(stop.since_ms), + limit_at: at(stop.limit_at_ms), + holding: stop.holding.clone(), + released: stop + .released + .iter() + .map(|(resource, after_ms)| ReleasedHold { + resource: resource.clone(), + after_ms: u32::try_from(*after_ms).unwrap_or(u32::MAX), + }) + .collect(), + }), } } @@ -1110,6 +1162,7 @@ pub(crate) fn control_error(error: ControlError) -> Error { // The bridge is no resource of the list the page acts on. ControlError::Bridge => ErrorCode::ResourceNotFound.into(), ControlError::NotStarting => ErrorCode::ServerNotStarting.into(), + ControlError::NotHeld => ErrorCode::StopNotHeld.into(), ControlError::ShuttingDown => ErrorCode::ShuttingDown.into(), ControlError::Launch(error) => ApiError::new(ErrorCode::LaunchFailed) .with("reason", serde_json::to_value(error.failure).unwrap_or_default()) diff --git a/crates/observer-app/src/supervision/setup.rs b/crates/observer-app/src/supervision/setup.rs index 41c76899..1b3b5a83 100644 --- a/crates/observer-app/src/supervision/setup.rs +++ b/crates/observer-app/src/supervision/setup.rs @@ -386,6 +386,7 @@ mod tests { extra_arguments: Vec::new(), hang_detection: true, hang_timeout_seconds: 360, + stop_hold_seconds: 60, } } diff --git a/crates/observer-app/src/tests.rs b/crates/observer-app/src/tests.rs index 74dfcb7b..95823db9 100644 --- a/crates/observer-app/src/tests.rs +++ b/crates/observer-app/src/tests.rs @@ -1200,6 +1200,7 @@ fn launch_settings() -> LaunchSettings { extra_arguments: Vec::new(), hang_detection: true, hang_timeout_seconds: 360, + stop_hold_seconds: 60, } } @@ -1222,6 +1223,7 @@ async fn launch_settings_are_stored_once_checked_with_what_changed_in_the_audit_ }], hang_detection: false, hang_timeout_seconds: 900, + stop_hold_seconds: 60, ..launch_settings() }; let second = lab @@ -1267,6 +1269,7 @@ async fn launch_settings_are_stored_once_checked_with_what_changed_in_the_audit_ "txadminEvents": { "before": null, "after": false }, "hangDetection": { "before": null, "after": true }, "hangTimeoutSeconds": { "before": null, "after": 360 }, + "stopHoldSeconds": { "before": null, "after": 60 }, }) ); } diff --git a/crates/observer-app/src/tools/tests.rs b/crates/observer-app/src/tools/tests.rs index 5f5c93d2..9a9ec052 100644 --- a/crates/observer-app/src/tools/tests.rs +++ b/crates/observer-app/src/tools/tests.rs @@ -70,6 +70,7 @@ impl Lab { extra_arguments: Vec::new(), hang_detection: true, hang_timeout_seconds: 360, + stop_hold_seconds: 60, }, version: 1, legacy_build_path: None, @@ -92,6 +93,8 @@ impl Lab { name: None, port: None, start: None, + stop_holders: Vec::new(), + stop: None, }); let tools = Tools::new(ToolsSetup { db: db.clone(), @@ -190,6 +193,7 @@ impl Lab { extra_arguments: Vec::new(), hang_detection: true, hang_timeout_seconds: 360, + stop_hold_seconds: 60, }, }, layout: Layout::new(build, Flavour::HOST), diff --git a/crates/observer-domain/src/audit.rs b/crates/observer-domain/src/audit.rs index efaefb3a..8b27fd55 100644 --- a/crates/observer-domain/src/audit.rs +++ b/crates/observer-domain/src/audit.rs @@ -40,6 +40,14 @@ pub enum AuditAction { /// Someone gave a start more time before Observer takes it for stuck. `details` holds the /// `minutes` given. ServerStartExtended, + /// A stop went on without the resources that held it: their limit ran out (`limit`), or + /// Windows was closing Observer's console and left no time to wait (`consoleClosed`). + /// `details` holds the `resources` that had not released the stop, the `reason` and the + /// `waitedSeconds`. + ServerStopHoldExpired, + /// Someone had FXServer quit without waiting for the resources that held the stop. + /// `details` holds the `resources` that had not released it. + ServerStopHoldSkipped, /// The owner saved the launch's cfg from the panel. The target is the file; `details` holds /// the lines `added` and `removed`, never their text. ServerCfgChanged, @@ -302,7 +310,7 @@ pub enum AuditAction { } impl AuditAction { - pub const ALL: [Self; 134] = [ + pub const ALL: [Self; 136] = [ Self::SetupCompleted, Self::SetupLinkCreated, Self::LoginSucceeded, @@ -323,6 +331,8 @@ impl AuditAction { Self::ServerStopped, Self::ServerRestarted, Self::ServerStartExtended, + Self::ServerStopHoldExpired, + Self::ServerStopHoldSkipped, Self::ServerCfgChanged, Self::ServerCfgRestored, Self::ConsoleCommandSent, @@ -462,6 +472,8 @@ impl AuditAction { Self::ServerStopped => "server_stopped", Self::ServerRestarted => "server_restarted", Self::ServerStartExtended => "server_start_extended", + Self::ServerStopHoldExpired => "server_stop_hold_expired", + Self::ServerStopHoldSkipped => "server_stop_hold_skipped", Self::ServerCfgChanged => "server_cfg_changed", Self::ServerCfgRestored => "server_cfg_restored", Self::ConsoleCommandSent => "console_command_sent", diff --git a/crates/observer-domain/src/error.rs b/crates/observer-domain/src/error.rs index d22e8c54..f8aebdb8 100644 --- a/crates/observer-domain/src/error.rs +++ b/crates/observer-domain/src/error.rs @@ -58,6 +58,8 @@ pub enum ErrorCode { ServerStopping, /// Only a start whose cfg still runs can be given more time. ServerNotStarting, + /// No resource holds a stop of FXServer now: there is no wait to skip. + StopNotHeld, /// The launch's cfg is not edited from the panel. Params: `reason`, a /// [`CfgRefusal`](crate::cfg::CfgRefusal). CfgNotEditable, diff --git a/crates/observer-domain/src/launch.rs b/crates/observer-domain/src/launch.rs index 3538d602..0bad5790 100644 --- a/crates/observer-domain/src/launch.rs +++ b/crates/observer-domain/src/launch.rs @@ -19,6 +19,12 @@ pub const MAX_EXTRA_ARGUMENTS: usize = 64; pub const DEFAULT_HANG_TIMEOUT_SECONDS: u32 = 360; pub const MIN_HANG_TIMEOUT_SECONDS: u32 = 60; pub const MAX_HANG_TIMEOUT_SECONDS: u32 = 3600; +/// How long a stop waits, at most, for the resources that hold it, in seconds: by default, and at +/// the extremes. The least is the notice every stop gives: set to it, a stop waits for no resource +/// longer than it does without one. +pub const DEFAULT_STOP_HOLD_SECONDS: u32 = 60; +pub const MIN_STOP_HOLD_SECONDS: u32 = 5; +pub const MAX_STOP_HOLD_SECONDS: u32 = 600; /// Names an extra argument may not set. Some would make FXServer escape Observer's supervision /// (`exec`, `citizen_dir`) or behave as if txAdmin ran it; the rest are Observer's own: two @@ -87,6 +93,11 @@ pub struct LaunchSettings { /// running server too, and the silence then counts from the change. #[serde(default = "hang_timeout_default")] pub hang_timeout_seconds: u32, + /// How long a stop waits, at most, for the resources that hold it through the bridge before + /// FXServer quits anyway: from `MIN_STOP_HOLD_SECONDS` to `MAX_STOP_HOLD_SECONDS`. A change + /// applies from the next stop. Settings saved before it existed have the default. + #[serde(default = "stop_hold_default")] + pub stop_hold_seconds: u32, } const fn hang_detection_default() -> bool { @@ -97,6 +108,10 @@ const fn hang_timeout_default() -> u32 { DEFAULT_HANG_TIMEOUT_SECONDS } +const fn stop_hold_default() -> u32 { + DEFAULT_STOP_HOLD_SECONDS +} + /// `GET /api/servers/default/launch` once the owner saved the settings, and what a change returns. #[derive(Debug, Clone, PartialEq, Eq, Serialize, TS)] #[serde(rename_all = "camelCase")] @@ -187,6 +202,7 @@ pub enum LaunchField { ArgumentName, ArgumentValue, HangTimeoutSeconds, + StopHoldSeconds, } #[derive(Debug, Clone, Copy, PartialEq, Eq, Serialize, TS)] @@ -223,7 +239,8 @@ pub enum LaunchProblem { /// More than `MAX_EXTRA_ARGUMENTS`. TooMany, /// A hang timeout outside `MIN_HANG_TIMEOUT_SECONDS` to `MAX_HANG_TIMEOUT_SECONDS`, or not a - /// whole number of minutes. + /// whole number of minutes; a stop's wait outside `MIN_STOP_HOLD_SECONDS` to + /// `MAX_STOP_HOLD_SECONDS`. OutOfRange, } @@ -273,6 +290,13 @@ impl LaunchSettings { Some(LaunchProblem::OutOfRange), ); } + if !(MIN_STOP_HOLD_SECONDS..=MAX_STOP_HOLD_SECONDS).contains(&self.stop_hold_seconds) { + note( + LaunchField::StopHoldSeconds, + None, + Some(LaunchProblem::OutOfRange), + ); + } issues } } @@ -440,6 +464,7 @@ mod tests { extra_arguments: vec![argument("sv_enforceGameBuild", "3258")], hang_detection: true, hang_timeout_seconds: DEFAULT_HANG_TIMEOUT_SECONDS, + stop_hold_seconds: DEFAULT_STOP_HOLD_SECONDS, } } @@ -838,6 +863,32 @@ mod tests { ); } + #[test] + fn a_stop_waits_for_resources_from_five_seconds_to_ten_minutes() { + let hold = |seconds: u32| { + LaunchSettings { + stop_hold_seconds: seconds, + ..settings() + } + .issues(Platform::Windows) + }; + + for seconds in [0, 4, 601, u32::MAX] { + assert_eq!( + hold(seconds), + [issue( + LaunchField::StopHoldSeconds, + None, + LaunchProblem::OutOfRange + )], + "{seconds} s" + ); + } + for seconds in [5, 6, 60, 599, 600] { + assert_eq!(hold(seconds), [], "{seconds} s"); + } + } + #[test] fn issues_name_their_field_and_the_argument_they_concern() { let broken = LaunchSettings { @@ -881,17 +932,20 @@ mod tests { "extraArguments": [{ "name": "sv_enforceGameBuild", "value": "3258" }], "hangDetection": true, "hangTimeoutSeconds": 360, + "stopHoldSeconds": 60, }) ); assert_eq!( serde_json::from_value::(json.clone()).unwrap(), settings() ); - // A body from before hang detection could be set still reads, with it on after six minutes. + // A body from before hang detection could be set still reads, with it on after six minutes, + // and one from before a stop could be held, with a minute for the resources that hold it. let mut before = json.clone(); let fields = before.as_object_mut().unwrap(); fields.remove("hangDetection"); fields.remove("hangTimeoutSeconds"); + fields.remove("stopHoldSeconds"); assert_eq!( serde_json::from_value::(before).unwrap(), settings() diff --git a/crates/observer-domain/src/server.rs b/crates/observer-domain/src/server.rs index 32614258..12cc2a27 100644 --- a/crates/observer-domain/src/server.rs +++ b/crates/observer-domain/src/server.rs @@ -216,6 +216,32 @@ pub struct StartProgress { pub extension_minutes: u32, } +/// A resource that released the stop it held. +#[derive(Debug, Clone, PartialEq, Eq, Serialize, TS)] +#[serde(rename_all = "camelCase")] +#[ts(export)] +pub struct ReleasedHold { + pub resource: String, + /// How long after `observer:shuttingDown` it released the stop, in milliseconds. + pub after_ms: u32, +} + +/// A stop the server's resources hold through the bridge: who Observer waits for before it has +/// FXServer quit, and until when. +#[derive(Debug, Clone, PartialEq, Eq, Serialize, TS)] +#[serde(rename_all = "camelCase")] +#[ts(export)] +pub struct StopProgress { + /// When `observer:shuttingDown` went out. + pub since: Timestamp, + /// When FXServer quits whoever still holds the stop. + pub limit_at: Timestamp, + /// The resources that hold the stop now, in name order. + pub holding: Vec, + /// Those that released it, in the order they did. + pub released: Vec, +} + /// The memory FXServer measures a streamed file by. #[derive(Debug, Clone, Copy, PartialEq, Eq, Serialize, TS)] #[serde(rename_all = "camelCase")] @@ -295,6 +321,11 @@ pub struct ServerStatus { pub port: Option, /// Only while FXServer is starting, from its first second. pub start: Option, + /// The resources that asked the bridge to hold each stop of the server that runs now, in name + /// order: a stop waits for them, up to the owner's limit. + pub stop_holders: Vec, + /// Only while FXServer is stopping and a resource holds the stop, or held it. + pub stop: Option, } #[derive(Debug, Clone, Copy, PartialEq, Eq, Serialize, TS)] diff --git a/crates/observer-fxserver/src/bridge.rs b/crates/observer-fxserver/src/bridge.rs index f7875c50..a8b7418d 100644 --- a/crates/observer-fxserver/src/bridge.rs +++ b/crates/observer-fxserver/src/bridge.rs @@ -1,6 +1,6 @@ //! The bridge resource Observer installs in every build: it turns Observer's commands into -//! server events, and reports the heartbeat, readiness, started resources, the JS heap and the -//! players back through the structured trace channel. The resource lives in `resource/observer`; +//! server events, and reports the heartbeat, readiness, started resources, the JS heap, the +//! players and the resources that hold a stop back through the structured trace channel. The resource lives in `resource/observer`; //! in a build it takes a name drawn for each start of FXServer. use std::fs; @@ -32,7 +32,12 @@ pub(crate) const REPORT_TYPE: &str = "observer"; /// The version of the server events the bridge raises; it must match `CONTRACT_VERSION` in /// `server.lua`. -pub const CONTRACT_VERSION: u32 = 6; +pub const CONTRACT_VERSION: u32 = 7; + +/// The most resources that can hold a stop at once; it must match `HOLDS_MAX` in `server.lua`. +pub const MAX_HOLDERS: usize = 64; +/// The longest name of a resource that holds a stop Observer keeps, in characters. +const MAX_HOLDER_CHARS: usize = 64; const FILES: [(&str, &str); 3] = [ ( @@ -150,9 +155,11 @@ pub enum BridgeEvent { reason: RestartSource, }, /// Raised again, with the time left, when a stop overtakes a restart before `quit`: the - /// latest one says what follows. + /// latest one says what follows. `quit` comes after `delay_ms` once no resource holds the + /// stop, and after `max_delay_ms` whoever still does. ShuttingDown { delay_ms: u64, + max_delay_ms: u64, reason: StopReason, by: String, }, @@ -752,6 +759,30 @@ pub enum Report { last: bool, resources: Vec, }, + /// The resources that hold the stop, all of them, whenever that changes and once the bridge + /// is ready. `stopping` once the bridge raised `observer:shuttingDown`: from then on, a + /// resource that left the list released the stop, or stopped when `stopped` names it. + Holds { + #[serde(default)] + stopping: bool, + #[serde(default)] + holding: Vec, + #[serde(default)] + stopped: Vec, + }, +} + +/// The name of a resource that holds a stop, as the console, the audit log and the panel may +/// show it: FXServer gives the folder's name, which anyone who writes to the server folder chose. +/// Control characters go, and what is left is cut at 64 characters; `None` when nothing is left. +pub fn holder_name(name: &str) -> Option { + let clean: String = name + .chars() + .filter(|character| !character.is_control()) + .take(MAX_HOLDER_CHARS) + .collect(); + let clean = clean.trim(); + (!clean.is_empty()).then(|| clean.to_owned()) } impl Report { @@ -802,6 +833,7 @@ mod tests { }, BridgeEvent::ShuttingDown { delay_ms: 0, + max_delay_ms: 0, reason: StopReason::Stop, by: String::new(), }, @@ -1784,7 +1816,13 @@ mod tests { assert_eq!( exports, - ["getContractVersion", "setPlayerLabel", "clearPlayerLabel"] + [ + "getContractVersion", + "setPlayerLabel", + "clearPlayerLabel", + "holdShutdown", + "releaseShutdown" + ] ); for export in exports { let call = format!("]:{export}("); @@ -1817,10 +1855,77 @@ mod tests { } } + #[test] + fn the_contract_gives_the_holds_refusals_and_the_bridge_keeps_as_many_holders_as_observer() { + let lua = FILES[1].1; + let start = CONTRACT + .find("## Holding a stop") + .expect("CONTRACT.md documents holding a stop"); + let section = &CONTRACT[start..]; + let section = §ion[..section[1..].find("\n## ").map_or(section.len(), |end| end + 1)]; + + assert!(lua.contains(&format!("local HOLDS_MAX = {MAX_HOLDERS}\n"))); + assert!(section.contains(&format!("{MAX_HOLDERS} resources"))); + for refusal in ["invalid", "tooMany", "notStopping", "notHeld"] { + assert!(lua.contains(&format!("return false, '{refusal}'")), "{refusal}"); + assert!(section.contains(&format!("`{refusal}`")), "{refusal}"); + } + for field in ["delayMs", "maxDelayMs"] { + assert!(section.contains(&format!("`{field}`")), "{field}"); + } + assert!(lua.contains("report('holds', {")); + } + + #[test] + fn a_holds_report_tells_who_holds_the_stop_and_who_stopped() { + let report = |payload: Value| { + Report::from_trace( + &TraceKind::Script { + resource: BRIDGE.to_owned(), + payload, + }, + BRIDGE, + ) + }; + + assert_eq!( + report(json!({ + "type": "observer", "kind": "holds", "stopping": true, + "holding": ["qb-inventory"], "stopped": ["garage"] + })), + Some(Report::Holds { + stopping: true, + holding: vec!["qb-inventory".to_owned()], + stopped: vec!["garage".to_owned()], + }) + ); + // No one holds: the bridge leaves an empty list out. + assert_eq!( + report(json!({ "type": "observer", "kind": "holds", "stopping": false })), + Some(Report::Holds { + stopping: false, + holding: Vec::new(), + stopped: Vec::new(), + }) + ); + } + + #[test] + fn a_holders_name_loses_its_control_characters_and_what_passes_its_length() { + assert_eq!(holder_name("qb-inventory").as_deref(), Some("qb-inventory")); + assert_eq!( + holder_name("bad\u{1b}[31m\r\nname").as_deref(), + Some("bad[31mname") + ); + assert_eq!(holder_name(&"n".repeat(80)).map(|name| name.len()), Some(64)); + assert_eq!(holder_name(" \t\n"), None); + } + #[test] fn an_event_travels_as_lowercase_hex_json() { let event = BridgeEvent::ShuttingDown { delay_ms: 5000, + max_delay_ms: 60_000, reason: StopReason::Restart, by: "alice\";\r\n\\".to_owned(), }; @@ -1835,7 +1940,9 @@ mod tests { decode(&hex), json!({ "event": "shuttingDown", - "payload": { "delayMs": 5000, "reason": "restart", "by": "alice\";\r\n\\" } + "payload": { + "delayMs": 5000, "maxDelayMs": 60000, "reason": "restart", "by": "alice\";\r\n\\" + } }) ); } diff --git a/crates/observer-fxserver/src/health.rs b/crates/observer-fxserver/src/health.rs index 876cccfd..f5aade40 100644 --- a/crates/observer-fxserver/src/health.rs +++ b/crates/observer-fxserver/src/health.rs @@ -915,6 +915,7 @@ mod tests { extra_arguments: Vec::new(), hang_detection, hang_timeout_seconds, + stop_hold_seconds: 60, } } diff --git a/crates/observer-fxserver/src/launch.rs b/crates/observer-fxserver/src/launch.rs index 72a56515..e12d3b4b 100644 --- a/crates/observer-fxserver/src/launch.rs +++ b/crates/observer-fxserver/src/launch.rs @@ -267,6 +267,7 @@ mod tests { extra_arguments: Vec::new(), hang_detection: true, hang_timeout_seconds: 360, + stop_hold_seconds: 60, } } diff --git a/crates/observer-fxserver/src/server_data.rs b/crates/observer-fxserver/src/server_data.rs index 285c8a37..de558dd7 100644 --- a/crates/observer-fxserver/src/server_data.rs +++ b/crates/observer-fxserver/src/server_data.rs @@ -872,6 +872,7 @@ exec ../shared.cfg }], hang_detection: true, hang_timeout_seconds: launch::DEFAULT_HANG_TIMEOUT_SECONDS, + stop_hold_seconds: launch::DEFAULT_STOP_HOLD_SECONDS, }; let read = cfg_convars(&settings); diff --git a/crates/observer-fxserver/src/stdin.rs b/crates/observer-fxserver/src/stdin.rs index baa41e16..78095965 100644 --- a/crates/observer-fxserver/src/stdin.rs +++ b/crates/observer-fxserver/src/stdin.rs @@ -445,6 +445,7 @@ mod tests { }, BridgeEvent::ShuttingDown { delay_ms: 5000, + max_delay_ms: 60_000, reason: StopReason::Stop, by: text.to_owned(), }, diff --git a/crates/observer-fxserver/src/supervisor.rs b/crates/observer-fxserver/src/supervisor.rs index 66b51ae7..4e514cb2 100644 --- a/crates/observer-fxserver/src/supervisor.rs +++ b/crates/observer-fxserver/src/supervisor.rs @@ -1,11 +1,15 @@ //! The supervisor: one task that starts FXServer, watches its health, stops it gracefully, and //! brings it back after a crash or a hang. Every change of state goes out on an event bus. //! +//! A graceful stop tells the server's resources first, through the bridge, and sends `quit` once +//! its notice has passed and every resource that holds the stop has released it, or once the +//! owner's limit for them has passed. A crash or a hang asks no one: there is nothing to wait for. +//! //! When the settings give pre-launch work, each spawn waits for it: the server shows as starting at //! once, the work runs as a task while requests are still answered, and FXServer is spawned only //! once it has ended. A stop or a shutdown meanwhile tells it to end, waits, and spawns nothing. -use std::collections::{HashMap, HashSet}; +use std::collections::{BTreeSet, HashMap, HashSet}; use std::fmt; use std::net::{Ipv4Addr, SocketAddr}; use std::path::PathBuf; @@ -14,7 +18,7 @@ use std::sync::{Arc, Mutex, PoisonError, Weak}; use std::time::{Duration, Instant}; use observer_domain::diagnostics::ProcessKind; -use observer_domain::launch::LaunchSettings; +use observer_domain::launch::{DEFAULT_STOP_HOLD_SECONDS, LaunchSettings}; use observer_domain::server::SpawnFailure; use observer_domain::server_data::CfgFinding; use observer_platform::{Exit, ExitWatch, Launch, Output, ProcessInfo, ProcessTree, TreeChange, TreeChanges}; @@ -211,6 +215,9 @@ pub struct StopTimings { /// After a fatal error, how long FXServer gets to exit before the tree is killed: on Windows /// it sometimes stays up behind an error dialog. pub fatal_exit: Duration, + /// From `observer:shuttingDown`, the longest a stop waits for the resources that hold it. + /// `None` takes the launch settings', which the owner sets; tests give their own. + pub hold: Option, } impl Default for StopTimings { @@ -220,6 +227,7 @@ impl Default for StopTimings { quit: Duration::from_secs(15), shortened: Duration::from_secs(4), fatal_exit: Duration::from_secs(5), + hold: None, } } } @@ -313,6 +321,28 @@ pub enum EventKind { ResourceList { resources: usize, }, + /// The wait of a stop for the resources that held it ended. + StopHeld { + /// Who had not released the stop. + unreleased: Vec, + /// From `observer:shuttingDown` to the end of the wait. + waited_ms: u64, + end: HoldEnd, + }, +} + +/// How the wait for the resources that held a stop ended. +#[derive(Debug, Clone, PartialEq, Eq, Serialize)] +#[serde(tag = "kind", rename_all = "snake_case")] +pub enum HoldEnd { + /// Each of them released the stop, or stopped. + Released, + /// Their limit passed. + Limit, + /// Someone had FXServer quit without waiting for them. + Skipped { by: String }, + /// The console was closing, and Windows leaves no time to wait. + Shortened, } /// A resource the server started or stopped while it ran. @@ -436,6 +466,22 @@ pub struct Status { pub txadmin_events: Option, /// How far the start has come, while the server is starting. pub start: Option, + /// The resources every stop of the run waits for, as the bridge last told them, in name order. + pub holders: Vec, + /// The resources a stop waits for, while one holds it or held it. + pub stop: Option, +} + +/// A stop that resources hold: who Observer waits for before `quit`, and until when. +#[derive(Debug, Clone, PartialEq, Eq, Serialize)] +pub struct StopStatus { + /// When `observer:shuttingDown` went out. + pub since_ms: i64, + /// When FXServer quits whoever still holds the stop. + pub limit_at_ms: i64, + pub holding: Vec, + /// Who released the stop and how long after `since_ms`, in milliseconds, in order. + pub released: Vec<(String, u64)>, } /// A start under way: what FXServer said of it, and how long Observer still waits for more. @@ -485,6 +531,8 @@ pub enum ControlError { Stopping, #[error("the server is not starting")] NotStarting, + #[error("no resource holds a stop of the server")] + NotHeld, #[error("Observer is shutting down")] ShuttingDown, #[error("cannot start FXServer: {0}")] @@ -522,6 +570,10 @@ enum Request { by: String, reply: Reply<()>, }, + QuitNow { + by: String, + reply: Reply>, + }, Announce { event: BridgeEvent, reply: Reply<()>, @@ -647,6 +699,8 @@ impl Supervisor { bridge: None, txadmin_events: None, start: None, + holders: Vec::new(), + stop: None, }; let (status_tx, status) = watch::channel(initial); let (readings_tx, readings) = watch::channel(Readings::default()); @@ -719,8 +773,8 @@ impl Supervisor { .await } - /// Stops the server gracefully: `observer:shuttingDown`, the notice delay, `quit`, then the - /// tree is killed if it is still there. + /// Stops the server gracefully: `observer:shuttingDown`, the notice delay and the wait for + /// the resources that hold the stop, `quit`, then the tree is killed if it is still there. pub async fn stop(&self, by: &str) -> Result<(), ControlError> { self.ask(|reply| Request::Stop { by: by.to_owned(), @@ -821,6 +875,17 @@ impl Supervisor { .await } + /// Has a stop under way send `quit` without waiting any longer for the resources that hold + /// it, and answers which had not released it. The notice every stop gives still runs to its + /// end. Only of a stop that a resource holds. + pub async fn quit_now(&self, by: &str) -> Result, ControlError> { + self.ask(|reply| Request::QuitNow { + by: by.to_owned(), + reply, + }) + .await + } + /// Raises an event of the integration contract, only on a running server whose bridge has /// reported: nothing is queued for a server still starting or already stopping. pub async fn announce(&self, event: BridgeEvent) -> Result<(), ControlError> { @@ -976,7 +1041,8 @@ enum Phase { deadline: Option, }, Running, - /// `observer:shuttingDown` is out; `quit` follows at `quit_at`. + /// `observer:shuttingDown` is out; `quit` follows at `quit_at`, or once the resources that + /// hold the stop have released it, whichever comes last, and at their limit anyway. Notice { quit_at: Instant, reason: StopReason, @@ -1064,6 +1130,29 @@ struct Run { ending: Option, /// Observer killed the tree: the exit status says nothing about the server then. killed: bool, + /// The resources every stop of this run waits for, as the bridge last told them. + holders: BTreeSet, + /// The wait of the stop under way, from `observer:shuttingDown` until `quit`. + hold: Option, +} + +/// The wait of one stop for the resources that hold it. +struct Hold { + since: Instant, + since_ms: i64, + /// When FXServer quits whoever still holds the stop. + limit_at: Instant, + limit: Duration, + holding: BTreeSet, + /// Who released the stop, and how long after it began, in order. + released: Vec<(String, Duration)>, +} + +impl Hold { + /// Whether a resource holds the stop, or held it. + fn concerns_someone(&self) -> bool { + !self.holding.is_empty() || !self.released.is_empty() + } } impl Run { @@ -1081,6 +1170,13 @@ impl Run { // Fire and forget: a line FXServer does not take is covered by the deadline that follows. drop(self.stdin.send(Write::System(line))); } + + /// How long the stop under way still waits, at most, for the resources that hold it. + fn limit_left(&self, now: Instant) -> Duration { + self.hold.as_ref().map_or(Duration::ZERO, |hold| { + hold.limit_at.saturating_duration_since(now) + }) + } } /// A launch prepared for its spawn, its cfg scan already handed on. @@ -1238,7 +1334,9 @@ impl Actor { fn deadline(&self) -> Instant { let phase = match self.phase { Phase::PreLaunch { deadline } => deadline, - Phase::Notice { quit_at, .. } => Some(quit_at), + Phase::Notice { quit_at, .. } => { + Some(self.held().map_or(quit_at, |hold| quit_at.max(hold.limit_at))) + } Phase::Quitting { kill_at } | Phase::Ending { kill_at } => Some(kill_at), Phase::Backoff { respawn_at } => Some(respawn_at), Phase::Idle | Phase::Running => None, @@ -1270,6 +1368,9 @@ impl Actor { Request::RestartScheduled { by, reply } => { let _ = reply.send(self.restart_scheduled(by)); } + Request::QuitNow { by, reply } => { + let _ = reply.send(self.quit_now(by)); + } Request::Announce { event, reply } => { let _ = reply.send(self.announce(event)); } @@ -1437,9 +1538,11 @@ impl Actor { // down, with the time they have left. if restarting && self.state == State::Stopping { if let Phase::Notice { quit_at, .. } = self.phase { - let left = quit_at.saturating_duration_since(Instant::now()); + let now = Instant::now(); + let left = quit_at.saturating_duration_since(now); run.system(SystemLine::Bridge(BridgeEvent::ShuttingDown { - delay_ms: u64::try_from(left.as_millis()).unwrap_or(u64::MAX), + delay_ms: millis(left), + max_delay_ms: millis(run.limit_left(now).max(left)), reason: StopReason::Stop, by: by.clone(), })); @@ -1574,10 +1677,19 @@ impl Actor { if quits { run.after = Some(After::Stop); } + let quitting = command.quits(); let written = run.stdin.send(Write::User { command, actor: actor.clone(), }); + // A `quit` typed during a stop ends it there, whoever holds it. + if quitting && matches!(self.phase, Phase::Notice { .. }) { + self.end_hold(HoldEnd::Skipped { by: actor.clone() }); + self.phase = Phase::Quitting { + kill_at: Instant::now() + self.settings.stop.quit, + }; + self.publish_status(); + } if quits { // FXServer quits by itself; Observer only makes sure it does. self.set_state(State::Stopping, Cause::ConsoleQuit { by: actor }); @@ -1622,13 +1734,15 @@ impl Actor { // Resources were told of a restart: they hear that the server stays down, with // the time they have left, as for a stop that overtakes a restart. let reason = if restarting { - let left = if shortened { - Duration::ZERO + let (left, limit) = if shortened { + (Duration::ZERO, Duration::ZERO) } else { - quit_at.saturating_duration_since(now) + let left = quit_at.saturating_duration_since(now); + (left, run.limit_left(now).max(left)) }; run.system(SystemLine::Bridge(BridgeEvent::ShuttingDown { - delay_ms: u64::try_from(left.as_millis()).unwrap_or(u64::MAX), + delay_ms: millis(left), + max_delay_ms: millis(limit), reason: StopReason::Shutdown, by: "observer".to_owned(), })); @@ -1642,6 +1756,7 @@ impl Actor { reason }; if shortened { + self.end_hold(HoldEnd::Shortened); self.quit(reason, self.settings.stop.shortened); } } @@ -1661,8 +1776,9 @@ impl Actor { } /// The stop sequence: the bridge event, the notice delay when the bridge is there to pass it - /// on and time allows, then `quit`. + /// on and time allows, the wait for the resources that hold the stop, then `quit`. fn begin_stop(&mut self, reason: StopReason, cause: Cause, after: After, shortened: bool) { + let limit = self.stop_hold(); let Some(run) = &mut self.run else { return; }; @@ -1676,21 +1792,61 @@ impl Actor { } else { self.settings.stop.notice }; + // Nothing holds a stop that gives no notice: Windows ends Observer within seconds. + let limit = if notice.is_zero() { + Duration::ZERO + } else { + limit.max(notice) + }; let bridge_ready = run.bridge_ready; if bridge_ready { run.system(SystemLine::Bridge(BridgeEvent::ShuttingDown { - delay_ms: u64::try_from(notice.as_millis()).unwrap_or(u64::MAX), + delay_ms: millis(notice), + max_delay_ms: millis(limit), reason, by, })); } - self.set_state(State::Stopping, cause); if bridge_ready && !notice.is_zero() { + let now = Instant::now(); + let holding = run.holders.clone(); + let waiting = (!holding.is_empty()).then(|| { + format!( + "waiting for {} to release the stop, {} at most", + listed(holding.iter()), + seconds(limit) + ) + }); + run.hold = Some(Hold { + since: now, + since_ms: now_ms(), + limit_at: now + limit, + limit, + holding, + released: Vec::new(), + }); self.phase = Phase::Notice { - quit_at: Instant::now() + notice, + quit_at: now + notice, reason, }; + self.set_state(State::Stopping, cause); + if let Some(waiting) = waiting { + self.note(&waiting); + } } else { + let unheld: Vec = run.holders.iter().cloned().collect(); + self.set_state(State::Stopping, cause); + if shortened && bridge_ready && !unheld.is_empty() { + self.note(&format!( + "the console is closing: no time left to wait for {}", + listed(unheld.iter()) + )); + self.emit(EventKind::StopHeld { + unreleased: unheld, + waited_ms: 0, + end: HoldEnd::Shortened, + }); + } let wait = if shortened { self.settings.stop.shortened } else { @@ -1700,13 +1856,170 @@ impl Actor { } } + /// The longest a stop waits for the resources that hold it: the owner's, from the launch + /// settings given last. + fn stop_hold(&self) -> Duration { + self.settings.stop.hold.unwrap_or_else(|| { + let seconds = self + .settings + .launch + .as_ref() + .map_or(DEFAULT_STOP_HOLD_SECONDS, |launch| { + launch.settings.stop_hold_seconds + }); + Duration::from_secs(u64::from(seconds)) + }) + } + + /// The wait of the stop under way, while a resource holds it. + fn held(&self) -> Option<&Hold> { + self.run + .as_ref() + .and_then(|run| run.hold.as_ref()) + .filter(|hold| !hold.holding.is_empty()) + } + + /// Sends `quit` once the notice has passed and no resource holds the stop, or once their + /// limit has. + fn settle_notice(&mut self, now: Instant) { + let Phase::Notice { quit_at, reason } = self.phase else { + return; + }; + if now < quit_at { + return; + } + let end = match self.held().map(|hold| hold.limit_at) { + Some(limit_at) if now < limit_at => return, + Some(_) => HoldEnd::Limit, + None => HoldEnd::Released, + }; + self.end_hold(end); + self.quit(reason, self.settings.stop.quit); + } + + /// Ends the wait for the resources that hold the stop and answers who had not released it. + /// Says how it ended when a resource held the stop at all. + fn end_hold(&mut self, end: HoldEnd) -> Vec { + let Some(hold) = self.run.as_mut().and_then(|run| run.hold.take()) else { + return Vec::new(); + }; + if !hold.concerns_someone() { + return Vec::new(); + } + let unreleased: Vec = hold.holding.iter().cloned().collect(); + let end = if unreleased.is_empty() { + HoldEnd::Released + } else { + end + }; + let who = listed(unreleased.iter()); + match &end { + // Each release was told as it came. + HoldEnd::Released => {} + HoldEnd::Limit => { + warn!( + resources = %who, + limit = ?hold.limit, + "resources did not release the stop in time; FXServer quits without them" + ); + self.note(&format!( + "{who} did not release the stop within {}; FXServer quits anyway", + seconds(hold.limit) + )); + } + HoldEnd::Skipped { by } => { + self.note(&format!("{by} had FXServer quit without waiting for {who}")); + } + HoldEnd::Shortened => { + warn!(resources = %who, "the console is closing: the stop does not wait for its resources"); + self.note(&format!("the console is closing: no time left to wait for {who}")); + } + } + self.emit(EventKind::StopHeld { + unreleased: unreleased.clone(), + waited_ms: millis(hold.since.elapsed()), + end, + }); + unreleased + } + + /// Has the stop under way go on without the resources that hold it. The notice every stop + /// gives still runs to its end. + fn quit_now(&mut self, by: String) -> Result, ControlError> { + if !matches!(self.phase, Phase::Notice { .. }) || self.held().is_none() { + return Err(ControlError::NotHeld); + } + let unreleased = self.end_hold(HoldEnd::Skipped { by }); + self.publish_status(); + self.settle_notice(Instant::now()); + Ok(unreleased) + } + + /// What the bridge tells of the resources that hold the stop: before a stop, who every stop + /// of this run waits for; during one, who still holds it. + fn holds(&mut self, stopping: bool, holding: &[String], stopped: &[String]) { + let Some(run) = &mut self.run else { + return; + }; + let clean = |names: &[String]| -> BTreeSet { + names + .iter() + .filter_map(|name| bridge::holder_name(name)) + .take(bridge::MAX_HOLDERS) + .collect() + }; + let holding = clean(holding); + let Some(hold) = &mut run.hold else { + if run.holders != holding { + run.holders = holding; + self.publish_status(); + } + return; + }; + let mut notes = Vec::new(); + if stopping { + let stopped = clean(stopped); + let waited = hold.since.elapsed(); + for name in hold.holding.difference(&holding) { + if stopped.contains(name) { + notes.push(format!("{name} stopped: the stop no longer waits for it")); + } else { + hold.released.push((name.clone(), waited)); + notes.push(format!( + "{name} released the stop after {:.1} s", + waited.as_secs_f64() + )); + } + } + for name in holding.difference(&hold.holding) { + hold.released.retain(|(released, _)| released != name); + notes.push(format!("{name} holds the stop too")); + } + hold.holding = holding; + } else { + // Told before the bridge heard of the stop: whoever asked meanwhile is waited for. + for name in holding { + if hold.holding.insert(name.clone()) { + notes.push(format!("{name} holds the stop too")); + } + } + } + for note in notes { + self.note(¬e); + } + self.publish_status(); + self.settle_notice(Instant::now()); + } + fn quit(&mut self, reason: StopReason, wait: Duration) { - if let Some(run) = &self.run { + if let Some(run) = &mut self.run { run.system(SystemLine::Quit(reason)); + run.hold = None; } self.phase = Phase::Quitting { kill_at: Instant::now() + wait, }; + self.publish_status(); } fn kill(&mut self) { @@ -1794,9 +2107,7 @@ impl Actor { Phase::PreLaunch { deadline: Some(deadline), } if now >= deadline => self.pre_launch_overdue(), - Phase::Notice { quit_at, reason } if now >= quit_at => { - self.quit(reason, self.settings.stop.quit); - } + Phase::Notice { .. } => self.settle_notice(now), Phase::Quitting { kill_at } | Phase::Ending { kill_at } if now >= kill_at => { if self.run.is_some() { self.note("FXServer did not end in time; killing its process tree"); @@ -1982,6 +2293,14 @@ impl Actor { run.bridge_ready = true; return; } + Some(Report::Holds { + stopping, + holding, + stopped, + }) => { + self.holds(stopping, &holding, &stopped); + return; + } Some(Report::Resources { started, events, @@ -2313,11 +2632,7 @@ impl Actor { warn!(%error, "cannot record FXServer's process group; a crash of Observer could leave it running"); } - let probe = self - .settings - .probe - .or(prepared.endpoint) - .unwrap_or_else(|| SocketAddr::from((Ipv4Addr::LOCALHOST, DEFAULT_PORT))); + let probe = self.probe_of(prepared.endpoint); let cancel = CancellationToken::new(); let (stdin, stdin_task) = StdinWriter::start(spawned.stdin, generation, Arc::clone(&self.console)); let progress = self.progress_of(prepared.plan); @@ -2391,10 +2706,21 @@ impl Actor { after: None, ending: None, killed: false, + holders: BTreeSet::new(), + hold: None, }; Ok((run, probe, prepared.warnings, prepared.settings)) } + /// Where a spawn is probed: the address the settings give, else the cfg's first TCP endpoint, + /// else FXServer's default port on this host. + fn probe_of(&self, endpoint: Option) -> SocketAddr { + self.settings + .probe + .or(endpoint) + .unwrap_or_else(|| SocketAddr::from((Ipv4Addr::LOCALHOST, DEFAULT_PORT))) + } + /// What a spawn says of its start from now on, kept as the latest start's. fn progress_of(&self, plan: start::Plan) -> Arc { let spawned_ms = now_ms(); @@ -2674,6 +3000,22 @@ impl Actor { .filter(|_| self.state == State::Starting) .and_then(|run| run.start.as_ref()) .map(|(status, _)| status.clone()), + holders: run.map_or_else(Vec::new, |run| run.holders.iter().cloned().collect()), + stop: run + .and_then(|run| run.hold.as_ref()) + .filter(|hold| hold.concerns_someone()) + .map(|hold| StopStatus { + since_ms: hold.since_ms, + limit_at_ms: hold + .since_ms + .saturating_add(i64::try_from(hold.limit.as_millis()).unwrap_or(i64::MAX)), + holding: hold.holding.iter().cloned().collect(), + released: hold + .released + .iter() + .map(|(name, after)| (name.clone(), millis(*after))) + .collect(), + }), }); } @@ -2914,6 +3256,38 @@ fn now_ms() -> i64 { jiff::Timestamp::now().as_millisecond() } +fn millis(duration: Duration) -> u64 { + u64::try_from(duration.as_millis()).unwrap_or(u64::MAX) +} + +/// A wait as the console tells it: `60 s`, `1.5 s`. +fn seconds(duration: Duration) -> String { + if duration.subsec_millis() == 0 { + format!("{} s", duration.as_secs()) + } else { + format!("{:.1} s", duration.as_secs_f64()) + } +} + +/// The most names a line of the console lists before it counts the rest. +const LISTED: usize = 8; + +/// `a`, `a and b`, `a, b and c`; past eight names, the rest are counted. +fn listed<'a>(names: impl ExactSizeIterator) -> String { + let total = names.len(); + let mut shown: Vec<&str> = names.take(LISTED).map(String::as_str).collect(); + let last = if total > LISTED { + format!("{} more", total - LISTED) + } else { + shown.pop().unwrap_or_default().to_owned() + }; + if shown.is_empty() { + last + } else { + format!("{} and {last}", shown.join(", ")) + } +} + #[cfg(test)] mod tests { use super::*; @@ -2938,6 +3312,21 @@ mod tests { ); } + #[test] + fn the_resources_that_hold_a_stop_are_listed_as_a_sentence_names_them() { + let names = |count: usize| -> Vec { (1..=count).map(|index| format!("r{index}")).collect() }; + + assert_eq!(listed(names(1).iter()), "r1"); + assert_eq!(listed(names(2).iter()), "r1 and r2"); + assert_eq!(listed(names(3).iter()), "r1, r2 and r3"); + assert_eq!( + listed(names(11).iter()), + "r1, r2, r3, r4, r5, r6, r7, r8 and 3 more" + ); + assert_eq!(seconds(Duration::from_secs(60)), "60 s"); + assert_eq!(seconds(Duration::from_millis(1500)), "1.5 s"); + } + #[test] fn licence_rejections_are_recognised_on_either_stream() { let lines = [ diff --git a/crates/observer-sftp/tests/sftp.rs b/crates/observer-sftp/tests/sftp.rs index c291672b..e6f68369 100644 --- a/crates/observer-sftp/tests/sftp.rs +++ b/crates/observer-sftp/tests/sftp.rs @@ -115,6 +115,7 @@ async fn seed(db: &Database, fingerprint: String, data_path: String) -> i64 { extra_arguments: Vec::new(), hang_detection: true, hang_timeout_seconds: 360, + stop_hold_seconds: 60, }, version: 1, legacy_build_path: None, diff --git a/crates/observer-store/migrations/0022_stop_hold.sql b/crates/observer-store/migrations/0022_stop_hold.sql new file mode 100644 index 00000000..6a5e1e25 --- /dev/null +++ b/crates/observer-store/migrations/0022_stop_hold.sql @@ -0,0 +1,5 @@ +-- How long a stop waits, at most, for the resources that hold it through the bridge, in seconds, +-- before FXServer quits anyway. Servers saved before get a minute. Five seconds is the notice every +-- stop gives: at that, a stop waits for no resource longer than it did before. +ALTER TABLE launch_settings ADD COLUMN stop_hold_seconds INTEGER NOT NULL DEFAULT 60 + CHECK (stop_hold_seconds BETWEEN 5 AND 600); diff --git a/crates/observer-store/src/launch.rs b/crates/observer-store/src/launch.rs index a6061c2b..4c8f07f4 100644 --- a/crates/observer-store/src/launch.rs +++ b/crates/observer-store/src/launch.rs @@ -13,7 +13,7 @@ pub fn get(conn: &Connection, server_id: &str) -> Result, S .query_row( "SELECT launch.data_path, launch.cfg_file, launch.onesync, launch.auto_start, launch.txadmin_events, launch.extra_arguments, launch.version, state.legacy_build_path, - launch.hang_detection, launch.hang_timeout_seconds + launch.hang_detection, launch.hang_timeout_seconds, launch.stop_hold_seconds FROM launch_settings AS launch LEFT JOIN artifact_state AS state ON state.server_id = launch.server_id WHERE launch.server_id = ?1", @@ -36,14 +36,16 @@ pub fn save( .map_err(|error| rusqlite::Error::ToSqlConversionFailure(Box::new(error)))?; conn.execute( "INSERT INTO launch_settings (server_id, data_path, cfg_file, onesync, auto_start, - txadmin_events, extra_arguments, version, updated_at, hang_detection, hang_timeout_seconds) - VALUES (?1, ?2, ?3, ?4, ?5, ?6, ?7, ?8, ?9, ?10, ?11) + txadmin_events, extra_arguments, version, updated_at, hang_detection, hang_timeout_seconds, + stop_hold_seconds) + VALUES (?1, ?2, ?3, ?4, ?5, ?6, ?7, ?8, ?9, ?10, ?11, ?12) ON CONFLICT (server_id) DO UPDATE SET data_path = excluded.data_path, cfg_file = excluded.cfg_file, onesync = excluded.onesync, auto_start = excluded.auto_start, txadmin_events = excluded.txadmin_events, extra_arguments = excluded.extra_arguments, version = excluded.version, updated_at = excluded.updated_at, hang_detection = excluded.hang_detection, - hang_timeout_seconds = excluded.hang_timeout_seconds", + hang_timeout_seconds = excluded.hang_timeout_seconds, + stop_hold_seconds = excluded.stop_hold_seconds", params![ server_id, settings.data_path, @@ -56,6 +58,7 @@ pub fn save( Utc(now), settings.hang_detection, settings.hang_timeout_seconds, + settings.stop_hold_seconds, ], )?; Ok(()) @@ -80,6 +83,7 @@ fn read(row: &Row<'_>) -> rusqlite::Result { .map_err(|error| rusqlite::Error::FromSqlConversionFailure(5, Type::Text, Box::new(error)))?, hang_detection: row.get(8)?, hang_timeout_seconds: row.get(9)?, + stop_hold_seconds: row.get(10)?, }; Ok(StoredLaunch { settings, @@ -114,6 +118,7 @@ mod tests { ], hang_detection: true, hang_timeout_seconds: 360, + stop_hold_seconds: 60, } } @@ -137,6 +142,7 @@ mod tests { extra_arguments: Vec::new(), hang_detection: false, hang_timeout_seconds: 900, + stop_hold_seconds: 120, ..settings() }; save(&conn, "other", &stored(changed.clone(), 1), now).unwrap(); diff --git a/crates/observer-store/src/migrations.rs b/crates/observer-store/src/migrations.rs index 24295c85..fc1ed477 100644 --- a/crates/observer-store/src/migrations.rs +++ b/crates/observer-store/src/migrations.rs @@ -30,6 +30,7 @@ const MIGRATIONS: &[M<'static>] = &[ M::up(include_str!("../migrations/0019_ban_edits_templates.sql")), M::up(include_str!("../migrations/0020_allowlist.sql")), M::up(include_str!("../migrations/0021_maintenance.sql")), + M::up(include_str!("../migrations/0022_stop_hold.sql")), ]; /// The schema version this build migrates to. @@ -276,4 +277,32 @@ mod tests { ) .unwrap(); } + + #[test] + fn a_0021_database_waits_a_minute_for_the_resources_that_hold_a_stop() { + let mut conn = Connection::open_in_memory().unwrap(); + let migrations = Migrations::from_slice(MIGRATIONS); + migrations.to_version(&mut conn, 21).unwrap(); + conn.execute( + "INSERT INTO launch_settings (server_id, data_path, cfg_file, onesync, auto_start, + txadmin_events, extra_arguments, version, updated_at, hang_detection, hang_timeout_seconds) + VALUES ('default', ?1, 'server.cfg', 'on', 1, 0, '[]', 4, '2026-11-11T09:00:00.000Z', 0, 900)", + [r"C:\FXServer\server-data"], + ) + .unwrap(); + + migrations.to_latest(&mut conn).unwrap(); + + let stored = crate::launch::get(&conn, "default").unwrap().unwrap(); + assert_eq!(stored.version, 4); + assert!(!stored.settings.hang_detection); + assert_eq!(stored.settings.hang_timeout_seconds, 900); + assert_eq!(stored.settings.stop_hold_seconds, 60); + for seconds in [0, 4, 601] { + let refused = conn.execute("UPDATE launch_settings SET stop_hold_seconds = ?1", [seconds]); + assert!(refused.is_err(), "{seconds}"); + } + conn.execute("UPDATE launch_settings SET stop_hold_seconds = 600", []) + .unwrap(); + } } diff --git a/crates/observer-web/src/api.rs b/crates/observer-web/src/api.rs index f8806e15..d3ad923a 100644 --- a/crates/observer-web/src/api.rs +++ b/crates/observer-web/src/api.rs @@ -229,6 +229,7 @@ pub(crate) fn routes() -> Vec { route(M::POST, "/servers/default/start/extend", control, servers::extend_start), route(M::GET, "/servers/default/start/warnings", read_tools, servers::start_warnings), route(M::POST, "/servers/default/stop", control, servers::stop), + route(M::POST, "/servers/default/stop/now", control, servers::stop_now), route(M::POST, "/servers/default/restart", control, servers::restart), route(M::POST, "/servers/default/console", command, servers::command), route(M::GET, "/servers/default/console/logs", logs, servers::log_files), diff --git a/crates/observer-web/src/api/servers.rs b/crates/observer-web/src/api/servers.rs index 85f0331b..0a5acd97 100644 --- a/crates/observer-web/src/api/servers.rs +++ b/crates/observer-web/src/api/servers.rs @@ -132,6 +132,15 @@ pub(crate) async fn stop( Ok(StatusCode::NO_CONTENT) } +/// Has the stop under way go on without the resources that still hold it. +pub(crate) async fn stop_now( + State(state): State, + Extension(caller): Extension, +) -> Result { + state.supervision.stop_now(&caller).await?; + Ok(StatusCode::NO_CONTENT) +} + pub(crate) async fn restart( State(state): State, Extension(caller): Extension, diff --git a/crates/observer-web/src/error.rs b/crates/observer-web/src/error.rs index 7f653f62..a439791c 100644 --- a/crates/observer-web/src/error.rs +++ b/crates/observer-web/src/error.rs @@ -86,6 +86,7 @@ fn status(code: ErrorCode) -> StatusCode { | ErrorCode::ServerNotRunning | ErrorCode::ServerStopping | ErrorCode::ServerNotStarting + | ErrorCode::StopNotHeld | ErrorCode::EntitiesNotListed | ErrorCode::EntitiesChanged | ErrorCode::EntitiesOutOfDate diff --git a/crates/observer-web/src/tests.rs b/crates/observer-web/src/tests.rs index 6905aa62..da79f4a4 100644 --- a/crates/observer-web/src/tests.rs +++ b/crates/observer-web/src/tests.rs @@ -1263,6 +1263,7 @@ fn launch_settings() -> Value { "extraArguments": [{ "name": "sv_enforceGameBuild", "value": "3258" }], "hangDetection": true, "hangTimeoutSeconds": 360, + "stopHoldSeconds": 60, }) } @@ -1326,6 +1327,7 @@ async fn launch_settings_with_issues_are_refused_with_each_issue() { settings["cfgFile"] = json!("../server.cfg"); settings["extraArguments"] = json!([{ "name": "exec", "value": "other.cfg; quit" }]); settings["hangTimeoutSeconds"] = json!(30); + settings["stopHoldSeconds"] = json!(3); let mut unknown = launch_settings(); unknown["onesync"] = json!("sometimes"); @@ -1349,6 +1351,7 @@ async fn launch_settings_with_issues_are_refused_with_each_issue() { { "field": "argumentName", "index": 0, "problem": "reserved" }, { "field": "argumentValue", "index": 0, "problem": "forbiddenCharacter" }, { "field": "hangTimeoutSeconds", "index": null, "problem": "outOfRange" }, + { "field": "stopHoldSeconds", "index": null, "problem": "outOfRange" }, ] }, }) ); diff --git a/crates/observer-web/src/tests/cfg.rs b/crates/observer-web/src/tests/cfg.rs index 2cad89c6..027fe602 100644 --- a/crates/observer-web/src/tests/cfg.rs +++ b/crates/observer-web/src/tests/cfg.rs @@ -50,6 +50,7 @@ impl Server { extra_arguments: Vec::new(), hang_detection: true, hang_timeout_seconds: 360, + stop_hold_seconds: 60, }, version: 1, legacy_build_path: None, diff --git a/crates/observer-web/src/tests/live.rs b/crates/observer-web/src/tests/live.rs index e207a39d..0527688e 100644 --- a/crates/observer-web/src/tests/live.rs +++ b/crates/observer-web/src/tests/live.rs @@ -548,6 +548,7 @@ async fn the_audit_log_names_changed_launch_settings_without_showing_what_only_t // Left out of the body, as a client from before sends it: the defaults. "hangDetection": { "before": null, "after": true }, "hangTimeoutSeconds": { "before": null, "after": 360 }, + "stopHoldSeconds": { "before": null, "after": 60 }, }) ); for shown in [event.to_string(), listed.text, exported.text] { diff --git a/crates/observer-web/src/tests/servers.rs b/crates/observer-web/src/tests/servers.rs index 70bbcb37..fe8bd34e 100644 --- a/crates/observer-web/src/tests/servers.rs +++ b/crates/observer-web/src/tests/servers.rs @@ -16,6 +16,7 @@ use super::{Server, Session}; const START: &str = "/api/servers/default/start"; const EXTEND: &str = "/api/servers/default/start/extend"; const STOP: &str = "/api/servers/default/stop"; +const STOP_NOW: &str = "/api/servers/default/stop/now"; const RESTART: &str = "/api/servers/default/restart"; const CONSOLE: &str = "/api/servers/default/console"; const LOGS: &str = "/api/servers/default/console/logs"; @@ -91,15 +92,26 @@ async fn starting_stopping_and_restarting_take_server_control_and_say_why_they_c let owner = server.owner().await; let viewer = server.member(&owner, "grace", "3").await; - for path in [START, STOP, EXTEND, RESTART] { + for path in [START, STOP, STOP_NOW, EXTEND, RESTART] { let refused = server.call(Method::POST, path, Some(&viewer), None).await; assert_eq!(refused.status, StatusCode::FORBIDDEN, "{path}"); assert_eq!(refused.json()["params"]["permission"], "serverControl"); } let denied = server.audited("permission_denied").await; - assert_eq!(denied.len(), 4); + assert_eq!(denied.len(), 5); assert_eq!(denied[0]["target"], format!("POST {RESTART}")); + let now = server.call(Method::POST, STOP_NOW, Some(&owner), None).await; + assert_eq!( + (now.status, now.code()), + (StatusCode::CONFLICT, json!("stop_not_held")), + "no resource holds a stop of a server that does not run" + ); + assert_eq!( + server.audited("server_stop_hold_skipped").await, + Vec::::new() + ); + let extend = server.call(Method::POST, EXTEND, Some(&owner), None).await; assert_eq!( (extend.status, extend.code()), @@ -171,6 +183,7 @@ async fn stored_settings_this_host_refuses_are_named_before_anything_starts() { extra_arguments: Vec::new(), hang_detection: true, hang_timeout_seconds: 360, + stop_hold_seconds: 60, }, version: 1, legacy_build_path: None, diff --git a/crates/observer-web/src/tests/setup.rs b/crates/observer-web/src/tests/setup.rs index bd1ebf2f..538ee9ea 100644 --- a/crates/observer-web/src/tests/setup.rs +++ b/crates/observer-web/src/tests/setup.rs @@ -61,6 +61,7 @@ fn settings(data_path: &str) -> Value { "extraArguments": [], "hangDetection": true, "hangTimeoutSeconds": 360, + "stopHoldSeconds": 60, }) } diff --git a/crates/observer-web/src/tests/tools.rs b/crates/observer-web/src/tests/tools.rs index 7a5d175c..4a54497a 100644 --- a/crates/observer-web/src/tests/tools.rs +++ b/crates/observer-web/src/tests/tools.rs @@ -49,6 +49,7 @@ impl Server { extra_arguments: Vec::new(), hang_detection: true, hang_timeout_seconds: 360, + stop_hold_seconds: 60, }, version: 1, legacy_build_path: None, diff --git a/crates/observer/src/desktop/mod.rs b/crates/observer/src/desktop/mod.rs index 6f0013ac..2db9994d 100644 --- a/crates/observer/src/desktop/mod.rs +++ b/crates/observer/src/desktop/mod.rs @@ -436,6 +436,8 @@ mod tests { name: None, port: None, start: None, + stop_holders: Vec::new(), + stop: None, } } diff --git a/crates/observer/src/fxserver.rs b/crates/observer/src/fxserver.rs index e39c6cf8..2b8bcb59 100644 --- a/crates/observer/src/fxserver.rs +++ b/crates/observer/src/fxserver.rs @@ -116,6 +116,7 @@ fn server_launch(args: RunArgs) -> anyhow::Result { .collect(), hang_detection: !args.no_hang_detection, hang_timeout_seconds: args.hang_timeout * 60, + stop_hold_seconds: observer_domain::launch::DEFAULT_STOP_HOLD_SECONDS, }, }) } diff --git a/crates/observer/src/shutdown.rs b/crates/observer/src/shutdown.rs index 08c25bae..eb0d5f75 100644 --- a/crates/observer/src/shutdown.rs +++ b/crates/observer/src/shutdown.rs @@ -3,9 +3,41 @@ //! SSH session) on Unix. use std::io; +#[cfg(any(target_os = "linux", test))] +use std::time::{Duration, Instant}; use observer_domain::audit::StopSource; +/// How long Observer asks its service manager for at a time while it stops, and how often. +#[cfg(any(target_os = "linux", test))] +pub const EXTEND_BY: Duration = Duration::from_secs(20); +#[cfg(target_os = "linux")] +pub const EXTEND_EVERY: Duration = Duration::from_secs(5); +/// What a stop still takes once no resource holds it: `quit`, the kill of what is left, then +/// Observer's own closing. +#[cfg(any(target_os = "linux", test))] +const AFTER_HOLD: Duration = Duration::from_secs(40); + +/// Whether Observer asks its service manager for more time to stop. A stop no resource holds fits +/// the unit's own limit, as it always did, and asks for nothing. While resources hold the stop +/// the wait is theirs, within the owner's limit: Observer asks for as long as it lasts, then for +/// what the stop takes after it, and no longer, so that a stop that hangs is still ended. +#[cfg(any(target_os = "linux", test))] +#[derive(Debug, Default)] +pub struct StopTime { + until: Option, +} + +#[cfg(any(target_os = "linux", test))] +impl StopTime { + pub fn asks(&mut self, held: bool, now: Instant) -> bool { + if held { + self.until = Some(now + AFTER_HOLD); + } + self.until.is_some_and(|until| now < until) + } +} + #[derive(Debug, Clone, Copy, PartialEq, Eq)] pub struct StopRequest { /// Windows is closing the console or ending the session, and ends the process about five @@ -118,6 +150,40 @@ impl Signals { } } +#[cfg(test)] +mod stop_time { + use super::*; + + #[test] + fn a_stop_no_resource_holds_asks_the_service_manager_for_nothing() { + let mut time = StopTime::default(); + let start = Instant::now(); + + for seconds in [0, 5, 30, 300] { + assert!( + !time.asks(false, start + Duration::from_secs(seconds)), + "{seconds} s" + ); + } + } + + #[test] + fn a_held_stop_asks_while_it_is_held_then_for_what_is_left_and_no_longer() { + let mut time = StopTime::default(); + let start = Instant::now(); + let at = |seconds| start + Duration::from_secs(seconds); + + assert!(!time.asks(false, at(0))); + for seconds in [5, 60, 590] { + assert!(time.asks(true, at(seconds)), "{seconds} s"); + } + assert!(time.asks(false, at(595))); + assert!(time.asks(false, at(629))); + assert!(!time.asks(false, at(630))); + assert!(EXTEND_BY < AFTER_HOLD); + } +} + #[cfg(all(test, windows))] mod tests { use super::*; diff --git a/crates/observer/src/systemd.rs b/crates/observer/src/systemd.rs index 9102b401..9264db1e 100644 --- a/crates/observer/src/systemd.rs +++ b/crates/observer/src/systemd.rs @@ -20,6 +20,8 @@ use tokio::task::JoinHandle; use tokio_util::sync::CancellationToken; use tracing::debug; +use crate::shutdown::{EXTEND_BY, EXTEND_EVERY, StopTime}; + /// The status line changes at most this often. const STATUS_EVERY: Duration = Duration::from_secs(1); @@ -211,32 +213,40 @@ impl Notifier { } } -/// `READY=1` once the panel answers, then the server's state as it changes, then `STOPPING=1`. -/// Ready means the panel answers, not that FXServer is up. +/// `READY=1` once the panel answers, then the server's state as it changes, then `STOPPING=1`, +/// and more time to stop for as long as resources hold the stop. Ready means the panel answers, +/// not that FXServer is up. pub struct Readiness { notifier: Option>, follower: Option>, + status: watch::Receiver, stop: CancellationToken, + closed: CancellationToken, } impl Readiness { pub fn start(supervision: &Supervision, port: u16) -> Self { let stop = CancellationToken::new(); + let closed = CancellationToken::new(); + let status = supervision.status(); let Some(notifier) = Notifier::from_env().map(Arc::new) else { return Self { notifier: None, follower: None, + status, stop, + closed, }; }; - let status = supervision.status(); let state = state(&status.borrow()); notifier.notify(&format!("READY=1\nSTATUS=Panel on port {port}, FXServer {state}")); - let follower = tokio::spawn(follow(Arc::clone(¬ifier), status, stop.clone())); + let follower = tokio::spawn(follow(Arc::clone(¬ifier), status.clone(), stop.clone())); Self { notifier: Some(notifier), follower: Some(follower), + status, stop, + closed, } } @@ -244,17 +254,55 @@ impl Readiness { self.stop.cancel(); if let Some(notifier) = &self.notifier { notifier.notify("STOPPING=1\nSTATUS=Stopping FXServer"); + tokio::spawn(ask_for_time( + Arc::clone(notifier), + self.status.clone(), + self.closed.clone(), + )); } } pub async fn close(self) { self.stop.cancel(); + self.closed.cancel(); if let Some(follower) = self.follower { let _ = follower.await; } } } +/// Asks systemd for the time the stop takes while resources hold it, which the unit's +/// `TimeoutStopSec` does not count on: see [`StopTime`]. systemd takes the ask from 236 on. +async fn ask_for_time( + notifier: Arc, + status: watch::Receiver, + closed: CancellationToken, +) { + let mut time = StopTime::default(); + let mut told = String::new(); + loop { + let holding = status + .borrow() + .stop + .as_ref() + .map(|stop| stop.holding.join(", ")) + .unwrap_or_default(); + if time.asks(!holding.is_empty(), std::time::Instant::now()) { + notifier.notify(&format!("EXTEND_TIMEOUT_USEC={}", EXTEND_BY.as_micros())); + } + if holding != told { + if !holding.is_empty() { + notifier.notify(&format!("STATUS=Stopping FXServer, waiting for {holding}")); + } + told = holding; + } + tokio::select! { + () = closed.cancelled() => return, + () = tokio::time::sleep(EXTEND_EVERY) => {} + } + } +} + async fn follow(notifier: Arc, mut status: watch::Receiver, stop: CancellationToken) { let mut sent = String::new(); loop { @@ -454,6 +502,8 @@ mod tests { name: None, port: None, start: None, + stop_holders: Vec::new(), + stop: None, }; assert_eq!(status_line(&status), "FXServer online · 12 / 64 players"); diff --git a/crates/observer/tests/tools.rs b/crates/observer/tests/tools.rs index bf5738a0..956b94f8 100644 --- a/crates/observer/tests/tools.rs +++ b/crates/observer/tests/tools.rs @@ -86,6 +86,7 @@ impl Host { extra_arguments: Vec::new(), hang_detection: true, hang_timeout_seconds: 360, + stop_hold_seconds: 60, }, version: 1, legacy_build_path: None, diff --git a/resource/CONTRACT.md b/resource/CONTRACT.md index 918af6c4..74206ec7 100644 --- a/resource/CONTRACT.md +++ b/resource/CONTRACT.md @@ -4,10 +4,10 @@ Observer never shows anything to players, but for what the owner writes: the ref for bans, one for maintenance mode, one for the allowlist, the kick message, and the name the server takes in FiveM's server list during maintenance. It tells your resources what is about to happen to the server, with data and no text of its own, and your resources decide what players see, what gets -saved and when. This page is that contract: the server events Observer raises, what they carry, what -your resources can tell Observer about players, how bans, maintenance mode and the allowlist keep -players out, how the staff's kicks, announcements and messages reach your resources, and what you -can rely on. +saved and when. This page is that contract: the server events Observer raises, what they carry, how +your resources hold a stop until they have saved, what they can tell Observer about players, how +bans, maintenance mode and the allowlist keep players out, how the staff's kicks, announcements and +messages reach your resources, and what you can rely on. ## The bridge @@ -36,10 +36,10 @@ local bridge = GetConvar('observer_bridge', '') -- empty when Observer did not s ## Version -This is contract version **6**. +This is contract version **7**. ```lua -local version = exports[GetConvar('observer_bridge', '')]:getContractVersion() -- 6 +local version = exports[GetConvar('observer_bridge', '')]:getContractVersion() -- 7 ``` Within a version, fields and `reason` values are only ever added. Ignore fields you do not know, and @@ -48,6 +48,8 @@ a `cause` you do not know as a refusal you have no details for. A field renamed change of meaning, is a new version. So is a new export of the bridge, so that a resource can check for it before calling it. +Version 7 added holding a stop: `holdShutdown` and `releaseShutdown`, and `maxDelayMs` in +`observer:shuttingDown`. A resource that never calls them sees a stop as it was before. Version 6 added the allowlist and maintenance mode, with `observer:maintenance`, and changed what `observer:playerRefused` means: it is raised for every player refused at connection, says what refused them in `cause`, and carries `ban`, `reason`, `endsAt` and `by` for a ban only. @@ -73,7 +75,7 @@ who signs in to nothing. No account can take either name. | `observer:restartScheduled` | At each warning before a restart, and at once for the nearest warning when a restart is planned or moved inside the warning window. | | `observer:restartSkipped` | A restart announced since this start of FXServer will not happen. | | `observer:restartRescheduled` | A restart announced since this start of FXServer moved to another time. | -| `observer:shuttingDown` | FXServer quits in `delayMs`: save now. | +| `observer:shuttingDown` | FXServer is about to quit: save now. See [Holding a stop](#holding-a-stop). | | `observer:startChanges` | Once per start of FXServer, when its files are hashed: what changed since the start before. | | `observer:playerRefused` | A connecting player was refused, by a ban, by maintenance mode or by the allowlist. See [Bans](#bans), [Maintenance mode](#maintenance-mode) and [Allowlist](#allowlist). | | `observer:playerBanned` | A ban is about to drop a connected player. See [Bans](#bans). | @@ -117,7 +119,8 @@ window. | Field | Type | Meaning | |---|---|---| -| `delayMs` | integer | Milliseconds until Observer sends `quit` (5,000 by default, 0 when Windows closes Observer's console). | +| `delayMs` | integer | Milliseconds until Observer sends `quit` when no resource holds the stop (5,000 by default, 0 when Windows closes Observer's console). | +| `maxDelayMs` | integer | Milliseconds until Observer sends `quit` whoever still holds the stop: the owner's limit, 60,000 by default. Never less than `delayMs`, and equal to it when nothing can hold this stop. | | `reason` | string | `stop`, `restart` (asked in the panel or the host's window), `scheduled` (the schedule or a single restart someone planned), or `shutdown` (Observer itself is stopping). | | `by` | string | Who asked, `local`, or `observer`. | @@ -158,8 +161,10 @@ by third parties. Nothing else of a file's name or contents is ever sent. again, from its nearest warning. - A restart that happens is always preceded by `observer:shuttingDown`, and no `observer:restart*` event follows it. A second `observer:shuttingDown` may follow when a stop, or Observer stopping, - overtakes a restart: the latest one says what happens. -- Nothing comes after `quit`. + overtakes a restart: the latest one says what happens, and `delayMs` and `maxDelayMs` give what + is left of the first one's. +- `quit` comes once `delayMs` has passed and no resource holds the stop, and at `maxDelayMs` at the + latest. Nothing comes after `quit`. - Delivery is best effort. A main loop that is stuck gets an event late, or never. - `observer:startChanges` comes once a run, never for a run that ended before its files were read. - An announced restart can also vanish without `observer:restartSkipped` when the server stops or @@ -167,6 +172,66 @@ by third parties. Nothing else of a file's name or contents is ever sent. - `observer:maintenance` says how things stand: the latest one of a run tells whether maintenance is on. A run that hears none started with maintenance off. +## Holding a stop + +A resource that saves when the server stops can hold the stop until it has saved. Ask once, as your +resource starts, and release each stop once your saves are done: + +```lua +local bridge = GetConvar('observer_bridge', '') +exports[bridge]:holdShutdown() + +AddEventHandler('observer:shuttingDown', function(payload) + -- your saves go here; they may wait on your database + exports[bridge]:releaseShutdown() +end) +``` + +From `holdShutdown()` on, every stop Observer announces waits for your resource: Observer sends +`quit` once `delayMs` has passed and every resource that holds the stop has released it. A resource +that never asks changes nothing: without one, `quit` comes after `delayMs`, as it did before +version 7. + +- The wait has a limit, which the owner sets in the panel: 60 seconds by default, from 5 seconds to + 10 minutes. `maxDelayMs` gives it. Past it Observer sends `quit` anyway, and names the resources + that had not released the stop in the console and the audit log. While it waits, the panel names + them too, and whoever may stop the server there can have FXServer quit without waiting for them: + `delayMs` still runs to its end. +- Both exports return `true`, or `false` and why. `holdShutdown`: `tooMany` (64 resources hold the + stop already) or `invalid` (not called by a resource). `releaseShutdown`: `notStopping` (no stop + is under way: the hold stays) or `notHeld` (your resource does not hold the stop). +- Release in every case, a failed save included: a resource that never releases costs every stop + the whole limit, and is named for it. +- A hold lasts until your resource stops. Started again, it asks again as it starts. A resource + that stops during a stop is no longer waited for. +- `holdShutdown()` called once a stop is under way counts as well, as long as it comes before + `quit`. Ask as your resource starts all the same: the stop is then held from its first instant, + even on a server too busy to run your handler within `delayMs`. +- The bridge keeps the holds. Should someone stop or restart the bridge itself, they are gone until + each resource asks again. + +What waits for the resources that hold a stop, and what does not: + +| What ends the run | Does it wait? | +|---|---| +| A stop or a restart, from the panel or the host's window | Yes. | +| A restart of the schedule, a single restart someone planned | Yes. The restart's time is when `observer:shuttingDown` is raised; FXServer is back that much later. | +| Observer installing its own update, a build of FXServer applied by a restart, a return to the last healthy build | Yes: each is a stop or a restart like any other. | +| Observer stopped by Ctrl+C, a signal or its service | Yes. Under systemd, Observer asks for the time it waits, which takes systemd 236 or later; anything else that stops Observer sets its own limit. | +| A second stop that overtakes the first | It is still the same stop: a release already given stands, and the limit counts from the first event. | +| Windows closing Observer's console, logging off or shutting down | No: Windows ends Observer within seconds. `delayMs` and `maxDelayMs` are 0, and a wait under way is cut short. | +| A crash, or a server that stopped responding | No: no event is raised, and there is no one to wait for. Save as you go, not only at the stop. | +| `quit` typed in the console | No: FXServer quits at once. | +| A stop while FXServer is still starting | No: the bridge has not reported yet, and nothing is raised. | + +A server whose main loop is stuck when the stop begins runs no handler. The resources that hold the +stop are then waited for until the limit, FXServer is told to quit, and 15 seconds later its +processes are killed. + +The backup Observer makes of the game's database before a restart runs once FXServer has exited: it +holds what your resource saved before it released the stop, and may miss what a resource cut off at +the limit was still saving. + ## Player labels Your resources can give each connected player a label, which Observer's panel shows beside their @@ -354,6 +419,9 @@ chat line. Any server resource can give a label: the exports are for your resources, which can already do anything on the server. Never call them with text a client sent you without checking it first. +Any server resource can hold a stop, too. The owner's limit bounds what it can cost, and Observer +names every resource that holds one. + The drawn name keeps away scripts written against a fixed name, and no resource can take it before the bridge starts. It is no secret from the server's own resources: any of them can list the resources, read `observer_bridge` and the bridge's files. Run only server resources you trust. @@ -383,7 +451,9 @@ restart warning and the `message` of a shutdown are always empty: Observer write txAdmin showed announcements and direct messages to players itself. Observer does not: a resource written for txAdmin's events shows them, the events alone show nothing. -## Not in version 6 +txAdmin has no way to hold a stop: a resource written for it gets `delay`, and saves within it. + +## Not in version 7 Exports to read the next restart, the server's state or whether maintenance is on come later. @@ -392,6 +462,7 @@ Exports to read the next restart, the server's state or whether maintenance is o [`observer_example`](observer_example) finds the bridge and checks the contract version when it starts, prints each event to the server console with its fields, and marks with short comments where a team plugs in its notifications, its cancellation notice, its saves and what shows the staff's -announcements and messages. Its console command +announcements and messages. It holds each stop for as long as its convar +`observer_example_save_ms` says, 0 by default, as a save would. Its console command `observer_example_label` gives a player a label, or clears it, to try the panel's side. It shows nothing to players. Copy what fits into your own resources rather than running it as is. diff --git a/resource/observer/server.lua b/resource/observer/server.lua index 5aa56056..f2bfc642 100644 --- a/resource/observer/server.lua +++ b/resource/observer/server.lua @@ -7,7 +7,7 @@ -- Bumped when a field is renamed or removed, when resources must find the bridge another way, and -- when the bridge gains an export, so that a resource can tell whether it is there; new fields keep -- the version. -local CONTRACT_VERSION = 6 +local CONTRACT_VERSION = 7 local HEARTBEAT_MS = 3000 local RESOURCES_SETTLE_MS = 500 local LABELS_SETTLE_MS = 1000 @@ -26,6 +26,9 @@ local VERDICT_POLL_MS = 50 local POSITIONS_EVERY_MIN_MS = 1000 local POSITIONS_EVERY_MAX_MS = 10000 local POSITIONS_FOR_MAX_MS = 60000 +-- The most resources that can hold a stop at once. +local HOLDS_MAX = 64 +local HOLDS_SETTLE_MS = 500 -- The events Observer may raise, and nothing else. local EVENTS = { @@ -194,6 +197,84 @@ exports('clearPlayerLabel', function(player) return true end) +local cfgRan = false + +-- The resources that hold the stop: Observer has FXServer quit once each has released it or +-- stopped, or once the owner's limit has passed. +local holds = {} +local holdsCount = 0 +-- Holders that stopped during the stop, which then release nothing: told once. +local holdsStopped = {} +local holdsPending = false +-- From the first observer:shuttingDown until FXServer quits. +local stopping = false + +local function reportHolds() + holdsPending = false + local holding = {} + for resource in pairs(holds) do + holding[#holding + 1] = resource + end + table.sort(holding) + local stopped = holdsStopped + holdsStopped = {} + report('holds', { + stopping = stopping, + holding = #holding > 0 and holding or nil, + stopped = #stopped > 0 and stopped or nil, + }) +end + +-- During a stop each release goes out at once: Observer waits on it. Before one, the resources +-- that ask as the server starts are told together, after `ready`. +local function holdsChanged() + if not cfgRan then + return + end + if stopping then + reportHolds() + return + end + if not holdsPending then + holdsPending = true + SetTimeout(HOLDS_SETTLE_MS, reportHolds) + end +end + +-- Every stop of the server waits for the calling resource from now on, until it releases the stop +-- or stops itself. Observer waits no longer than the owner's limit, and names who held past it. +exports('holdShutdown', function() + local resource = GetInvokingResource() + if type(resource) ~= 'string' or resource == '' then + return false, 'invalid' + end + if holds[resource] then + return true + end + if holdsCount >= HOLDS_MAX then + return false, 'tooMany' + end + holds[resource] = true + holdsCount = holdsCount + 1 + holdsChanged() + return true +end) + +-- The calling resource has saved what it had to: the stop under way no longer waits for it. +exports('releaseShutdown', function() + if not stopping then + return false, 'notStopping' + end + local resource = GetInvokingResource() + if type(resource) ~= 'string' or not holds[resource] then + return false, 'notHeld' + end + holds[resource] = nil + holdsCount = holdsCount - 1 + holdsChanged() + return true +end) + -- The connections waiting for Observer's verdict, by request: false until it comes. local verdicts = {} local lastRequest = 0 @@ -995,13 +1076,13 @@ AddEventHandler('onResourceListRefresh', function() CreateThread(reportResourceList) end) -local cfgRan = false - -- The thread first runs once the cfg has run, so `ready` means its resources were started. CreateThread(function() cfgRan = true report('ready', { contractVersion = CONTRACT_VERSION }) report('resources', { started = startedResources() }) + -- Always, even with none: a bridge started again holds nothing of what the one before held. + reportHolds() reportResourceList() reportPlayers() while true do @@ -1044,6 +1125,15 @@ AddEventHandler('onResourceStart', function(name) end) AddEventHandler('onResourceStop', function(name) resourcesChanged(name, 'stop') + -- A stopped resource saves nothing more: no stop waits for it. + if holds[name] then + holds[name] = nil + holdsCount = holdsCount - 1 + if stopping then + holdsStopped[#holdsStopped + 1] = name + end + holdsChanged() + end end) local function secondsUntil(at) @@ -1136,6 +1226,10 @@ RegisterCommand('observer_cmd', function(source, args) if not EVENTS[command.event] then return end + local stop = command.event == 'shuttingDown' + if stop then + stopping = true + end TriggerEvent('observer:' .. command.event, command.payload) local txadmin = TXADMIN[command.event] if txadmin and txadminEvents() then @@ -1143,4 +1237,9 @@ RegisterCommand('observer_cmd', function(source, args) TriggerEvent(event[1], event[2]) end end + if stop then + -- Who holds the stop once every handler has run up to its first wait: Observer counts on + -- this report to know the event was raised. + reportHolds() + end end, true) diff --git a/resource/observer_example/server.lua b/resource/observer_example/server.lua index cc5be8ac..39e974b4 100644 --- a/resource/observer_example/server.lua +++ b/resource/observer_example/server.lua @@ -1,10 +1,11 @@ -- Listens to the server events of Observer's integration contract (resource/CONTRACT.md) and prints --- each one with its fields, and gives players labels for Observer's panel from the console. It --- shows nothing to players: the comments mark where your own notifications, cancellation notices, --- saves, labels and the staff's announcements and messages would go. +-- each one with its fields, holds each stop until its saves are done, and gives players labels for +-- Observer's panel from the console. It shows nothing to players: the comments mark where your own +-- notifications, cancellation notices, saves, labels and the staff's announcements and messages +-- would go. -- The contract this resource was written for. -local CONTRACT_VERSION = 6 +local CONTRACT_VERSION = 7 local function log(text) print(('[observer_example] %s'):format(text)) @@ -38,8 +39,22 @@ CreateThread(function() log(('^3Observer speaks contract %s, this resource was written for %d^7'):format( show(version), CONTRACT_VERSION)) end + -- Once, as the resource starts: from now on every stop waits until this resource has released + -- it, within the limit the owner set. Holding a stop came with contract 7. + if type(version) == 'number' and version >= 7 then + local ok, refused = exports[bridge]:holdShutdown() + if not ok then + log('the stop is not held: ' .. tostring(refused)) + end + end end) +-- Stands for your saves: it takes observer_example_save_ms milliseconds, 0 by default. Set the +-- convar to try a stop that waits, and past the owner's limit to see Observer quit without it. +local function save() + Wait(GetConvarInt('observer_example_save_ms', 0)) +end + -- AddEventHandler only: never RegisterNetEvent these names, or clients could raise them. AddEventHandler('observer:restartScheduled', function(payload) @@ -58,8 +73,15 @@ AddEventHandler('observer:restartRescheduled', function(payload) end) AddEventHandler('observer:shuttingDown', function(payload) - log('shuttingDown ' .. fields(payload, { 'delayMs', 'reason', 'by' })) - -- Your saves go here: FXServer quits in payload.delayMs milliseconds. + log('shuttingDown ' .. fields(payload, { 'delayMs', 'maxDelayMs', 'reason', 'by' })) + -- Your saves go here: FXServer quits once this resource has released the stop, and after + -- payload.maxDelayMs milliseconds whatever it still saves. Release even when a save failed. + local saved, failure = pcall(save) + if not saved then + log('the save failed: ' .. tostring(failure)) + end + local ok, refused = exports[GetConvar('observer_bridge', '')]:releaseShutdown() + log(ok and 'released the stop' or ('the stop was not released: ' .. tostring(refused))) end) AddEventHandler('observer:startChanges', function(payload) diff --git a/web/src/api/generated/AuditAction.ts b/web/src/api/generated/AuditAction.ts index 0930659d..b091406c 100644 --- a/web/src/api/generated/AuditAction.ts +++ b/web/src/api/generated/AuditAction.ts @@ -3,4 +3,4 @@ /** * Every action the audit log records. Stored by name, so a variant is never renamed. */ -export type AuditAction = "setup_completed" | "setup_link_created" | "login_succeeded" | "login_failed" | "logout" | "session_revoked" | "password_changed" | "user_created" | "user_deleted" | "user_permissions_changed" | "user_password_reset" | "user_unlocked" | "permission_denied" | "audit_exported" | "reauthenticated" | "launch_settings_changed" | "server_started" | "server_stopped" | "server_restarted" | "server_start_extended" | "server_cfg_changed" | "server_cfg_restored" | "console_command_sent" | "console_log_downloaded" | "server_crash_loop" | "schedule_changed" | "scheduled_restart_skipped" | "scheduled_restart_restored" | "scheduled_restart_delayed" | "scheduled_restart_missed" | "one_off_restart_planned" | "one_off_restart_cancelled" | "build_install_started" | "build_install_cancelled" | "build_install_finished" | "build_selected" | "pending_build_set" | "pending_build_cancelled" | "pending_build_applied" | "pending_build_dropped" | "probation_passed" | "probation_failed" | "build_rolled_back" | "build_deleted" | "artifact_settings_changed" | "observer_stopped" | "tree_process_started" | "hang_snapshot_taken" | "crash_file_downloaded" | "crash_files_deleted" | "tree_records_full" | "file_session_opened" | "file_session_closed" | "file_login_failed" | "file_written" | "file_deleted" | "folder_created" | "folder_removed" | "file_renamed" | "file_refused" | "file_records_full" | "file_group_created" | "file_group_changed" | "file_group_deleted" | "file_access_changed" | "service_access_created" | "service_access_changed" | "service_access_deleted" | "file_key_added" | "file_key_removed" | "file_session_disconnected" | "file_settings_changed" | "file_host_key_created" | "player_forgotten" | "players_imported" | "players_retention_changed" | "player_drops_exported" | "player_banned" | "ban_lifted" | "ban_edited" | "bans_settings_changed" | "map_image_changed" | "map_settings_changed" | "entities_deleted" | "entities_settings_changed" | "drop_rates_exported" | "drops_retention_changed" | "change_contents_viewed" | "change_settings_changed" | "change_contents_purged" | "change_verify_requested" | "change_check_requested" | "tool_settings_changed" | "tool_files_changed" | "tool_files_restored" | "tool_fix_staged" | "tool_fix_unstaged" | "feature_changed" | "sftp_listen_changed" | "debug_host_known" | "backup_settings_changed" | "backup_destination_created" | "backup_destination_changed" | "backup_destination_deleted" | "backup_finished" | "backup_cancelled" | "backup_downloaded" | "backup_deleted" | "backups_expired" | "statistics_link_dismissed" | "statistics_link_restored" | "observer_update_started" | "observer_update_cancelled" | "observer_update_finished" | "resource_started" | "resource_stopped" | "resource_restarted" | "resources_rescanned" | "player_kicked" | "everyone_kicked" | "kick_settings_changed" | "announcement_sent" | "direct_message_sent" | "allowlist_request_approved" | "allowlist_request_denied" | "allowlist_requests_denied" | "allowlist_licence_approved" | "allowlist_approval_removed" | "allowlist_settings_changed" | "maintenance_started" | "maintenance_ended" | "maintenance_pass_added" | "maintenance_pass_removed" | "maintenance_settings_changed"; +export type AuditAction = "setup_completed" | "setup_link_created" | "login_succeeded" | "login_failed" | "logout" | "session_revoked" | "password_changed" | "user_created" | "user_deleted" | "user_permissions_changed" | "user_password_reset" | "user_unlocked" | "permission_denied" | "audit_exported" | "reauthenticated" | "launch_settings_changed" | "server_started" | "server_stopped" | "server_restarted" | "server_start_extended" | "server_stop_hold_expired" | "server_stop_hold_skipped" | "server_cfg_changed" | "server_cfg_restored" | "console_command_sent" | "console_log_downloaded" | "server_crash_loop" | "schedule_changed" | "scheduled_restart_skipped" | "scheduled_restart_restored" | "scheduled_restart_delayed" | "scheduled_restart_missed" | "one_off_restart_planned" | "one_off_restart_cancelled" | "build_install_started" | "build_install_cancelled" | "build_install_finished" | "build_selected" | "pending_build_set" | "pending_build_cancelled" | "pending_build_applied" | "pending_build_dropped" | "probation_passed" | "probation_failed" | "build_rolled_back" | "build_deleted" | "artifact_settings_changed" | "observer_stopped" | "tree_process_started" | "hang_snapshot_taken" | "crash_file_downloaded" | "crash_files_deleted" | "tree_records_full" | "file_session_opened" | "file_session_closed" | "file_login_failed" | "file_written" | "file_deleted" | "folder_created" | "folder_removed" | "file_renamed" | "file_refused" | "file_records_full" | "file_group_created" | "file_group_changed" | "file_group_deleted" | "file_access_changed" | "service_access_created" | "service_access_changed" | "service_access_deleted" | "file_key_added" | "file_key_removed" | "file_session_disconnected" | "file_settings_changed" | "file_host_key_created" | "player_forgotten" | "players_imported" | "players_retention_changed" | "player_drops_exported" | "player_banned" | "ban_lifted" | "ban_edited" | "bans_settings_changed" | "map_image_changed" | "map_settings_changed" | "entities_deleted" | "entities_settings_changed" | "drop_rates_exported" | "drops_retention_changed" | "change_contents_viewed" | "change_settings_changed" | "change_contents_purged" | "change_verify_requested" | "change_check_requested" | "tool_settings_changed" | "tool_files_changed" | "tool_files_restored" | "tool_fix_staged" | "tool_fix_unstaged" | "feature_changed" | "sftp_listen_changed" | "debug_host_known" | "backup_settings_changed" | "backup_destination_created" | "backup_destination_changed" | "backup_destination_deleted" | "backup_finished" | "backup_cancelled" | "backup_downloaded" | "backup_deleted" | "backups_expired" | "statistics_link_dismissed" | "statistics_link_restored" | "observer_update_started" | "observer_update_cancelled" | "observer_update_finished" | "resource_started" | "resource_stopped" | "resource_restarted" | "resources_rescanned" | "player_kicked" | "everyone_kicked" | "kick_settings_changed" | "announcement_sent" | "direct_message_sent" | "allowlist_request_approved" | "allowlist_request_denied" | "allowlist_requests_denied" | "allowlist_licence_approved" | "allowlist_approval_removed" | "allowlist_settings_changed" | "maintenance_started" | "maintenance_ended" | "maintenance_pass_added" | "maintenance_pass_removed" | "maintenance_settings_changed"; diff --git a/web/src/api/generated/ErrorCode.ts b/web/src/api/generated/ErrorCode.ts index ebc333d3..0278526c 100644 --- a/web/src/api/generated/ErrorCode.ts +++ b/web/src/api/generated/ErrorCode.ts @@ -4,4 +4,4 @@ * Why the API refused a request. The panel turns the code into a message; the API never sends * sentences. */ -export type ErrorCode = "unauthenticated" | "invalid_credentials" | "temporary_password_expired" | "too_many_attempts" | "busy" | "too_many_sockets" | "password_change_required" | "reauth_required" | "wrong_password" | "forbidden" | "owner_only" | "self_edit" | "owner_protected" | "escalation" | "hierarchy" | "conflict" | "not_found" | "name_taken" | "invalid_username" | "password_too_short" | "password_too_long" | "password_unchanged" | "unknown_permissions" | "invalid_launch_settings" | "launch_not_configured" | "launch_failed" | "server_running" | "server_not_running" | "server_stopping" | "server_not_starting" | "cfg_not_editable" | "cfg_changed" | "invalid_cfg_text" | "cfg_version_not_found" | "shutting_down" | "command_refused" | "too_many_commands" | "already_set_up" | "invalid_setup_token" | "origin_mismatch" | "unknown_host" | "json_required" | "invalid_request" | "internal" | "invalid_schedule" | "nothing_to_skip" | "already_skipped" | "nothing_to_restore" | "nothing_to_delay" | "delay_too_long" | "no_one_off" | "job_running" | "no_job" | "job_committing" | "catalog_unavailable" | "build_not_listed" | "not_downloadable" | "already_installed" | "end_of_life" | "build_not_installed" | "build_broken" | "kvp_rollback" | "no_scheduled_restart" | "already_selected" | "no_pending" | "build_protected" | "build_in_use" | "invalid_artifact_settings" | "no_build_selected" | "invalid_import_folder" | "crash_not_found" | "crash_file_not_found" | "crash_file_too_large" | "setup_blocked" | "invalid_rule" | "invalid_public_key" | "key_in_use" | "too_many_keys" | "invalid_access" | "player_not_found" | "address_search" | "invalid_search" | "invalid_players_settings" | "invalid_players_file" | "invalid_drops_settings" | "ban_not_found" | "ban_not_active" | "invalid_ban" | "invalid_bans_settings" | "player_not_connected" | "invalid_kick" | "invalid_kick_settings" | "invalid_message" | "allowlist_request_not_found" | "approval_not_found" | "already_approved" | "invalid_approval" | "invalid_allowlist_settings" | "pass_not_found" | "pass_exists" | "invalid_pass" | "too_many_passes" | "invalid_maintenance_settings" | "invalid_map_image" | "no_map_image" | "invalid_map_settings" | "entities_not_listed" | "entities_changed" | "entities_out_of_date" | "entities_deleting" | "too_many_entities" | "invalid_entities_settings" | "changes_unavailable" | "start_not_found" | "content_hidden" | "content_not_kept" | "diff_too_large" | "check_running" | "check_too_soon" | "invalid_glob" | "plan_changed" | "server_not_stopped" | "tool_not_available" | "feature_disabled" | "feature_locked" | "sftp_listen_pinned" | "invalid_sftp_listen" | "backup_running" | "invalid_backup_settings" | "invalid_backup_destination" | "backup_not_configured" | "backup_copy_unavailable" | "update_not_available" | "update_running" | "no_update" | "update_restarting" | "update_blocked" | "resources_not_listed" | "resource_not_found" | "resource_name_refused" | "resource_busy" | "resource_changed"; +export type ErrorCode = "unauthenticated" | "invalid_credentials" | "temporary_password_expired" | "too_many_attempts" | "busy" | "too_many_sockets" | "password_change_required" | "reauth_required" | "wrong_password" | "forbidden" | "owner_only" | "self_edit" | "owner_protected" | "escalation" | "hierarchy" | "conflict" | "not_found" | "name_taken" | "invalid_username" | "password_too_short" | "password_too_long" | "password_unchanged" | "unknown_permissions" | "invalid_launch_settings" | "launch_not_configured" | "launch_failed" | "server_running" | "server_not_running" | "server_stopping" | "server_not_starting" | "stop_not_held" | "cfg_not_editable" | "cfg_changed" | "invalid_cfg_text" | "cfg_version_not_found" | "shutting_down" | "command_refused" | "too_many_commands" | "already_set_up" | "invalid_setup_token" | "origin_mismatch" | "unknown_host" | "json_required" | "invalid_request" | "internal" | "invalid_schedule" | "nothing_to_skip" | "already_skipped" | "nothing_to_restore" | "nothing_to_delay" | "delay_too_long" | "no_one_off" | "job_running" | "no_job" | "job_committing" | "catalog_unavailable" | "build_not_listed" | "not_downloadable" | "already_installed" | "end_of_life" | "build_not_installed" | "build_broken" | "kvp_rollback" | "no_scheduled_restart" | "already_selected" | "no_pending" | "build_protected" | "build_in_use" | "invalid_artifact_settings" | "no_build_selected" | "invalid_import_folder" | "crash_not_found" | "crash_file_not_found" | "crash_file_too_large" | "setup_blocked" | "invalid_rule" | "invalid_public_key" | "key_in_use" | "too_many_keys" | "invalid_access" | "player_not_found" | "address_search" | "invalid_search" | "invalid_players_settings" | "invalid_players_file" | "invalid_drops_settings" | "ban_not_found" | "ban_not_active" | "invalid_ban" | "invalid_bans_settings" | "player_not_connected" | "invalid_kick" | "invalid_kick_settings" | "invalid_message" | "allowlist_request_not_found" | "approval_not_found" | "already_approved" | "invalid_approval" | "invalid_allowlist_settings" | "pass_not_found" | "pass_exists" | "invalid_pass" | "too_many_passes" | "invalid_maintenance_settings" | "invalid_map_image" | "no_map_image" | "invalid_map_settings" | "entities_not_listed" | "entities_changed" | "entities_out_of_date" | "entities_deleting" | "too_many_entities" | "invalid_entities_settings" | "changes_unavailable" | "start_not_found" | "content_hidden" | "content_not_kept" | "diff_too_large" | "check_running" | "check_too_soon" | "invalid_glob" | "plan_changed" | "server_not_stopped" | "tool_not_available" | "feature_disabled" | "feature_locked" | "sftp_listen_pinned" | "invalid_sftp_listen" | "backup_running" | "invalid_backup_settings" | "invalid_backup_destination" | "backup_not_configured" | "backup_copy_unavailable" | "update_not_available" | "update_running" | "no_update" | "update_restarting" | "update_blocked" | "resources_not_listed" | "resource_not_found" | "resource_name_refused" | "resource_busy" | "resource_changed"; diff --git a/web/src/api/generated/LaunchField.ts b/web/src/api/generated/LaunchField.ts index bac6c58d..95e7780d 100644 --- a/web/src/api/generated/LaunchField.ts +++ b/web/src/api/generated/LaunchField.ts @@ -1,3 +1,3 @@ // This file was generated by [ts-rs](https://github.com/Aleph-Alpha/ts-rs). Do not edit this file manually. -export type LaunchField = "dataPath" | "cfgFile" | "extraArguments" | "argumentName" | "argumentValue" | "hangTimeoutSeconds"; +export type LaunchField = "dataPath" | "cfgFile" | "extraArguments" | "argumentName" | "argumentValue" | "hangTimeoutSeconds" | "stopHoldSeconds"; diff --git a/web/src/api/generated/LaunchSettings.ts b/web/src/api/generated/LaunchSettings.ts index ac15ec29..60c98bb3 100644 --- a/web/src/api/generated/LaunchSettings.ts +++ b/web/src/api/generated/LaunchSettings.ts @@ -38,4 +38,10 @@ hangDetection: boolean, * `MIN_HANG_TIMEOUT_SECONDS` to `MAX_HANG_TIMEOUT_SECONDS`. A change applies at once, to a * running server too, and the silence then counts from the change. */ -hangTimeoutSeconds: number, }; +hangTimeoutSeconds: number, +/** + * How long a stop waits, at most, for the resources that hold it through the bridge before + * FXServer quits anyway: from `MIN_STOP_HOLD_SECONDS` to `MAX_STOP_HOLD_SECONDS`. A change + * applies from the next stop. Settings saved before it existed have the default. + */ +stopHoldSeconds: number, }; diff --git a/web/src/api/generated/ReleasedHold.ts b/web/src/api/generated/ReleasedHold.ts new file mode 100644 index 00000000..74d3dc48 --- /dev/null +++ b/web/src/api/generated/ReleasedHold.ts @@ -0,0 +1,10 @@ +// This file was generated by [ts-rs](https://github.com/Aleph-Alpha/ts-rs). Do not edit this file manually. + +/** + * A resource that released the stop it held. + */ +export type ReleasedHold = { resource: string, +/** + * How long after `observer:shuttingDown` it released the stop, in milliseconds. + */ +afterMs: number, }; diff --git a/web/src/api/generated/ServerStatus.ts b/web/src/api/generated/ServerStatus.ts index 31d4eabd..3133e315 100644 --- a/web/src/api/generated/ServerStatus.ts +++ b/web/src/api/generated/ServerStatus.ts @@ -5,6 +5,7 @@ import type { PlayerCount } from "./PlayerCount"; import type { ServerState } from "./ServerState"; import type { StartProgress } from "./StartProgress"; import type { StateCause } from "./StateCause"; +import type { StopProgress } from "./StopProgress"; /** * The `server.status` topic. @@ -41,4 +42,13 @@ port: number | null, /** * Only while FXServer is starting, from its first second. */ -start: StartProgress | null, }; +start: StartProgress | null, +/** + * The resources that asked the bridge to hold each stop of the server that runs now, in name + * order: a stop waits for them, up to the owner's limit. + */ +stopHolders: Array, +/** + * Only while FXServer is stopping and a resource holds the stop, or held it. + */ +stop: StopProgress | null, }; diff --git a/web/src/api/generated/StopProgress.ts b/web/src/api/generated/StopProgress.ts new file mode 100644 index 00000000..c94e05d0 --- /dev/null +++ b/web/src/api/generated/StopProgress.ts @@ -0,0 +1,24 @@ +// This file was generated by [ts-rs](https://github.com/Aleph-Alpha/ts-rs). Do not edit this file manually. +import type { ReleasedHold } from "./ReleasedHold"; + +/** + * A stop the server's resources hold through the bridge: who Observer waits for before it has + * FXServer quit, and until when. + */ +export type StopProgress = { +/** + * When `observer:shuttingDown` went out. + */ +since: string, +/** + * When FXServer quits whoever still holds the stop. + */ +limitAt: string, +/** + * The resources that hold the stop now, in name order. + */ +holding: Array, +/** + * Those that released it, in the order they did. + */ +released: Array, }; diff --git a/web/src/api/launch.ts b/web/src/api/launch.ts index e0319de8..e18c679c 100644 --- a/web/src/api/launch.ts +++ b/web/src/api/launch.ts @@ -29,6 +29,7 @@ export const DEFAULT_LAUNCH: LaunchSettings = { extraArguments: [], hangDetection: true, hangTimeoutSeconds: 360, + stopHoldSeconds: 60, }; const FIELDS = { @@ -38,6 +39,7 @@ const FIELDS = { argumentName: true, argumentValue: true, hangTimeoutSeconds: true, + stopHoldSeconds: true, } satisfies Record; const PROBLEMS = { @@ -90,12 +92,15 @@ export const changedSettings = (saved: LaunchSettings, draft: LaunchSettings) => export const countChanges = (saved: LaunchSettings, draft: LaunchSettings) => changedSettings(saved, draft).length; -/** The settings a running server takes at once; every other one waits for the next start. */ +/** The settings a running server takes at once. */ export const HANG_SETTINGS: ReadonlySet = new Set([ 'hangDetection', 'hangTimeoutSeconds', ]); +/** The seconds a stop waits for the resources that hold it, at the least and at the most. */ +export const STOP_HOLD_RANGE = { min: 5, max: 600 } as const; + /** The draft as it is sent: names and paths lose the spaces a paste leaves around them. */ export const cleaned = (draft: LaunchSettings): LaunchSettings => ({ ...draft, diff --git a/web/src/api/server.ts b/web/src/api/server.ts index 07ce1eec..4dcb38d5 100644 --- a/web/src/api/server.ts +++ b/web/src/api/server.ts @@ -11,6 +11,8 @@ const SERVER = '/servers/default'; export const startServer = () => send('POST', `${SERVER}/start`); export const stopServer = () => send('POST', `${SERVER}/stop`); export const restartServer = () => send('POST', `${SERVER}/restart`); +/** Has the stop under way go on without the resources that still hold it. */ +export const stopNow = () => send('POST', `${SERVER}/stop/now`); /** Gives the start under way more time before Observer takes it for stuck. */ export const extendStart = () => send('POST', `${SERVER}/start/extend`); diff --git a/web/src/audit/details.test.ts b/web/src/audit/details.test.ts index 55417ae6..c982a5bc 100644 --- a/web/src/audit/details.test.ts +++ b/web/src/audit/details.test.ts @@ -149,6 +149,30 @@ describe('auditDetails', () => { hangTimeoutSeconds: { before: 360, after: 900 }, }), ).toBe('Hang detection: yes → no · Restart a hung server after: 6 min → 15 min'); + expect(auditDetails(en, format, { stopHoldSeconds: { before: 60, after: 120 } })).toBe( + 'Wait for resources at a stop: 60 s → 120 s', + ); + }); + + it('should name the resources a stop went on without, why, and after how long', () => { + expect( + auditDetails( + en, + format, + { resources: ['esx_vehicleshop', 'qb-inventory'], reason: 'limit', waitedSeconds: 60 }, + 'server_stop_hold_expired', + ), + ).toBe('Resources: esx_vehicleshop, qb-inventory · Reason: their limit passed · Waited: 60 s'); + expect( + auditDetails(en, format, { + resources: ['qb-inventory'], + reason: 'consoleClosed', + waitedSeconds: 0, + }), + ).toBe("Resources: qb-inventory · Reason: Windows was closing Observer's console · Waited: 0 s"); + expect(auditDetails(en, format, { resources: ['qb-inventory'] }, 'server_stop_hold_skipped')).toBe( + 'Resources: qb-inventory', + ); }); it('should name the step a failed launch stopped at', () => { diff --git a/web/src/audit/details.ts b/web/src/audit/details.ts index 282f5fe6..77d38557 100644 --- a/web/src/audit/details.ts +++ b/web/src/audit/details.ts @@ -37,6 +37,7 @@ const LISTS = new Set([ 'excluded', 'hidden', 'dependants', + 'resources', ]); const NESTED = new Set(['scheduled', 'dropped']); /** The schedule's settings counted in minutes. */ @@ -206,7 +207,12 @@ const word = (t: Messages, format: Format, key: string, value: unknown): string if (key === 'generation') { return t.diagnostics.processes.generation(value); } - if (key === 'lateBySeconds' || key === 'everySeconds') { + if ( + key === 'lateBySeconds' || + key === 'everySeconds' || + key === 'waitedSeconds' || + key === 'stopHoldSeconds' + ) { return t.audit.seconds(format.number(value)); } // Kept in seconds, in the minutes the launch settings take it in. @@ -301,6 +307,9 @@ const word = (t: Messages, format: Format, key: string, value: unknown): string if (key === 'reason' && has(t.audit.missReasons, value)) { return t.audit.missReasons[value]; } + if (key === 'reason' && has(t.audit.holdReasons, value)) { + return t.audit.holdReasons[value]; + } if (key === 'reason' && has(t.audit.dropReasons, value)) { return t.audit.dropReasons[value]; } diff --git a/web/src/i18n/en.ts b/web/src/i18n/en.ts index 57e15fb3..7d1fc6ef 100644 --- a/web/src/i18n/en.ts +++ b/web/src/i18n/en.ts @@ -569,6 +569,8 @@ export const en = { unknown: 'n/a', upFor: (uptime: string) => `up ${uptime}`, forTime: (lasted: string) => `for ${lasted}`, + waitingFor: (resources: number) => + `waiting for ${count(resources, { one: 'resource', other: 'resources' })}`, resources: (started: number, of: number | null) => of === null ? count(started, { one: 'resource', other: 'resources' }) @@ -4574,6 +4576,16 @@ export const en = { : `${count(players, { one: 'player is', other: 'players are' })} connected. They will be disconnected.`, noticeFirst: 'Resources receive observer:shuttingDown first, then FXServer quits; whatever does not end in 15 seconds is killed.', + heldBy: (resources: string[]) => + `${list(resources)} ${resources.length === 1 ? 'holds' : 'hold'} the stop: FXServer quits once ${resources.length === 1 ? 'it has' : 'they have'} released it, or once the limit in the launch settings has passed.`, + waiting: (resources: string[]) => `Waiting for ${list(resources)} to release the stop.`, + quitsIn: (left: string) => `FXServer quits in ${left} at the latest.`, + quitsNow: 'FXServer quits now.', + quitNow: 'Quit now', + quitNowTitle: 'Quit without waiting?', + quitNowBody: (resources: string[]) => + `${list(resources)} ${resources.length === 1 ? 'has' : 'have'} not released the stop: what ${resources.length === 1 ? 'it is' : 'they are'} still saving may be lost.`, + quitNowAudit: 'The audit log keeps who did, and the resources left behind.', confirmRestart: 'Restart', confirmStop: 'Stop server', keepStoppedTitle: 'Keep FXServer stopped?', @@ -4943,6 +4955,16 @@ export const en = { savedHang: 'Saved. Hang detection applies at once, to a running server too.', savedBoth: 'Saved. Hang detection applies at once, to a running server too; the other settings from the next start of FXServer, a restart after a crash included.', + // A save that changed the wait at a stop: what each kind of setting it changed applies from. + savedParts: (parts: ('hang' | 'stopHold' | 'rest')[]) => { + const applies = { + hang: 'hang detection applies at once, to a running server too', + stopHold: 'the wait for resources applies from the next stop', + rest: 'the other settings apply from the next start of FXServer, a restart after a crash included', + }; + const said = parts.map((part) => applies[part]).join('; '); + return `Saved. ${said.charAt(0).toUpperCase()}${said.slice(1)}.`; + }, problems: { required: 'Fill this in.', tooLong: 'Too long: 1,024 characters at most.', @@ -5600,6 +5622,10 @@ export const en = { label: 'Wait before restarting', about: 'Minutes of silence, from 1 to 60, 6 by default. While FXServer starts, each resource it starts counts as a sign of life: raise the delay if one resource alone takes longer, as a clothing pack can on a first start.', }, + stopHold: { + label: 'Wait for resources at a stop', + about: 'Seconds, from 5 to 600, 60 by default. A resource that holds the stop through the bridge is waited for until it has saved, this long at most: past it FXServer quits anyway, and the console and the audit log name the resource. At 5, the notice every stop gives, no resource is waited for longer.', + }, extraArguments: { label: 'Convars', about: "Each goes on FXServer's command line as +set . FXServer applies them before your cfg, so a convar your cfg sets too keeps the cfg's value. Keep secrets in the cfg: anyone on the host can read a command line.", @@ -5929,7 +5955,11 @@ export const en = { launch: { runSetup: 'Run the setup', openArtifacts: 'Open the Artifacts page', - groups: { files: 'Files', game: 'Game', hang: 'Hang detection' }, + groups: { files: 'Files', game: 'Game', hang: 'Hang detection', stop: 'Stop' }, + stopHoldRange: 'A whole number of seconds, from 5 to 600.', + heldBy: (resources: string[]) => + `${resources.length === 1 ? 'Holds' : 'Hold'} each stop now: ${list(resources)}.`, + heldByNone: 'No resource of the running server holds its stops.', onesync: { on: { name: 'On', @@ -6341,6 +6371,8 @@ export const en = { server_stopped: 'Server stopped', server_restarted: 'Server restarted', server_start_extended: 'Start given more time', + server_stop_hold_expired: 'Stop not released by its resources', + server_stop_hold_skipped: 'Wait for resources skipped', server_cfg_changed: 'server.cfg saved', server_cfg_restored: 'server.cfg version put back', tool_fix_staged: 'Tool fix staged for the next start', @@ -6530,6 +6562,11 @@ export const en = { argumentsRemoved: (names: string) => `removed ${names}`, argumentsReordered: 'reordered', seconds: (value: string) => `${value} s`, + // Why a stop went on without the resources that held it. + holdReasons: { + limit: 'their limit passed', + consoleClosed: "Windows was closing Observer's console", + }, yes: 'yes', no: 'no', detail: { @@ -6582,6 +6619,9 @@ export const en = { txadminEvents: 'txAdmin events', hangDetection: 'Hang detection', hangTimeoutSeconds: 'Restart a hung server after', + stopHoldSeconds: 'Wait for resources at a stop', + resources: 'Resources', + waitedSeconds: 'Waited', extraArguments: 'Extra arguments', setup: 'From the server setup', command: 'Command', @@ -7012,6 +7052,7 @@ export const en = { server_not_running: 'FXServer is not running.', server_stopping: 'FXServer is stopping. Start it again once it has stopped.', server_not_starting: 'FXServer is no longer starting.', + stop_not_held: 'No resource holds the stop any more.', cfg_not_editable: 'The cfg is not edited from the panel.', cfg_changed: 'The cfg changed on disk since it was read.', invalid_cfg_text: (params) => { diff --git a/web/src/live/messages.test.ts b/web/src/live/messages.test.ts index 31414f71..81659e70 100644 --- a/web/src/live/messages.test.ts +++ b/web/src/live/messages.test.ts @@ -17,6 +17,8 @@ const STATUS = { restartAt: '2026-10-28T14:02:17Z', launch: 'ready', start: null, + stopHolders: [], + stop: null, }; const ONLINE = { @@ -56,6 +58,19 @@ const STARTING = { }, }; +const STOPPING = { + ...ONLINE, + state: 'stopping', + cause: { kind: 'restart', by: 'ada' }, + stopHolders: ['esx_vehicleshop', 'qb-inventory'], + stop: { + since: '2026-10-28T16:00:00Z', + limitAt: '2026-10-28T16:01:00Z', + holding: ['qb-inventory'], + released: [{ resource: 'esx_vehicleshop', afterMs: 2400 }], + }, +}; + const LINE = [1_761_660_127_000_001, 1_761_660_127_123, 3, 'command', 'ada', 'ensure chat', 0]; const SAMPLE = { @@ -108,6 +123,8 @@ describe('parseServerMessage', () => { { type: 'snapshot', topic: 'audit', data: { latestId: null } }, { type: 'snapshot', topic: 'server.status', data: STATUS }, { type: 'event', topic: 'server.status', data: ONLINE }, + { type: 'event', topic: 'server.status', data: { ...ONLINE, stopHolders: ['qb-inventory'] } }, + { type: 'event', topic: 'server.status', data: STOPPING }, { type: 'event', topic: 'server.status', data: STARTING }, { type: 'event', @@ -242,6 +259,17 @@ describe('parseServerMessage', () => { data: { ...SAMPLE, children: [{ ...SAMPLE.children[0], workingSet: -1 }] }, }, { type: 'snapshot', topic: 'server.status', data: { ...STATUS, state: 'exploded' } }, + { type: 'event', topic: 'server.status', data: { ...ONLINE, stopHolders: [7] } }, + { + type: 'event', + topic: 'server.status', + data: { ...STOPPING, stop: { ...STOPPING.stop, limitAt: 'soon' } }, + }, + { + type: 'event', + topic: 'server.status', + data: { ...STOPPING, stop: { ...STOPPING.stop, released: [{ resource: 'chat' }] } }, + }, { type: 'event', topic: 'server.status', diff --git a/web/src/live/messages.ts b/web/src/live/messages.ts index 33f24d0a..412e83ff 100644 --- a/web/src/live/messages.ts +++ b/web/src/live/messages.ts @@ -191,6 +191,8 @@ const AUDIT_ACTIONS = { server_stopped: true, server_restarted: true, server_start_extended: true, + server_stop_hold_expired: true, + server_stop_hold_skipped: true, server_cfg_changed: true, server_cfg_restored: true, tool_fix_staged: true, @@ -506,6 +508,18 @@ const isStartProgress = (value: unknown) => orNull(isTimestamp)(value.stuckAt) && isCount(value.extensionMinutes); +const isTexts = (value: unknown): value is string[] => Array.isArray(value) && value.every(isText); + +const isStopProgress = (value: unknown) => + isRecord(value) && + isTimestamp(value.since) && + isTimestamp(value.limitAt) && + isTexts(value.holding) && + Array.isArray(value.released) && + value.released.every( + (released) => isRecord(released) && isText(released.resource) && isCount(released.afterMs), + ); + export const isServerStatus = (value: unknown): value is ServerStatus => isRecord(value) && oneOf(SERVER_STATES)(value.state) && @@ -518,7 +532,9 @@ export const isServerStatus = (value: unknown): value is ServerStatus => (value.players === null || isPlayers(value.players)) && orNull(isTimestamp)(value.restartAt) && oneOf(READINESS)(value.launch) && - (value.start === null || isStartProgress(value.start)); + (value.start === null || isStartProgress(value.start)) && + isTexts(value.stopHolders) && + (value.stop === null || isStopProgress(value.stop)); const isCounts = (value: unknown): value is number[] => Array.isArray(value) && value.every(isCount); diff --git a/web/src/overview/StartCard.test.tsx b/web/src/overview/StartCard.test.tsx index 65235f2b..bb5faafc 100644 --- a/web/src/overview/StartCard.test.tsx +++ b/web/src/overview/StartCard.test.tsx @@ -75,6 +75,8 @@ const status = (start: StartProgress): ServerStatus => ({ name: null, port: null, start, + stopHolders: [], + stop: null, }); const card = (start: StartProgress = START, me: Me = OWNER) => diff --git a/web/src/pages/ArchetypesPage.test.tsx b/web/src/pages/ArchetypesPage.test.tsx index 6330439e..35ba380f 100644 --- a/web/src/pages/ArchetypesPage.test.tsx +++ b/web/src/pages/ArchetypesPage.test.tsx @@ -277,6 +277,8 @@ const statusOf = (state: ServerState) => ({ restartAt: null, launch: 'ready', start: null, + stopHolders: [], + stop: null, }); const answer = (status: number, body?: unknown) => diff --git a/web/src/pages/ArtifactsPage.test.tsx b/web/src/pages/ArtifactsPage.test.tsx index 8a1dc248..5cb6f549 100644 --- a/web/src/pages/ArtifactsPage.test.tsx +++ b/web/src/pages/ArtifactsPage.test.tsx @@ -51,6 +51,8 @@ const ONLINE = { restartAt: null, launch: 'ready', start: null, + stopHolders: [], + stop: null, }; const SCHEDULE = { diff --git a/web/src/pages/OverviewPage.test.tsx b/web/src/pages/OverviewPage.test.tsx index 33192850..ac90200b 100644 --- a/web/src/pages/OverviewPage.test.tsx +++ b/web/src/pages/OverviewPage.test.tsx @@ -331,6 +331,8 @@ const hungFor = async (me: Me) => { name: null, port: null, start: null, + stopHolders: [], + stop: null, } satisfies ServerStatus, }); return view; @@ -940,6 +942,8 @@ describe('OverviewPage', () => { name: null, port: null, start: null, + stopHolders: [], + stop: null, } satisfies ServerStatus; say({ type: 'snapshot', topic: 'server.status', data: online }); diff --git a/web/src/pages/ResourcesPage.test.tsx b/web/src/pages/ResourcesPage.test.tsx index b67c79c3..866865aa 100644 --- a/web/src/pages/ResourcesPage.test.tsx +++ b/web/src/pages/ResourcesPage.test.tsx @@ -93,6 +93,8 @@ const STARTING: ServerStatus = { stuckAt: null, extensionMinutes: 15, }, + stopHolders: [], + stop: null, }; const settle = () => act(() => new Promise((resolve) => setTimeout(resolve, 0))); diff --git a/web/src/pages/SchedulePage.test.tsx b/web/src/pages/SchedulePage.test.tsx index d53d5e4d..7507fad6 100644 --- a/web/src/pages/SchedulePage.test.tsx +++ b/web/src/pages/SchedulePage.test.tsx @@ -65,6 +65,8 @@ const ONLINE = { restartAt: null, launch: 'ready', start: null, + stopHolders: [], + stop: null, }; /** The text of what a field is described by, element by element. */ diff --git a/web/src/pages/ServerSetupPage.test.tsx b/web/src/pages/ServerSetupPage.test.tsx index c9d731d0..36206379 100644 --- a/web/src/pages/ServerSetupPage.test.tsx +++ b/web/src/pages/ServerSetupPage.test.tsx @@ -70,6 +70,8 @@ const STOPPED: ServerStatus = { name: null, port: null, start: null, + stopHolders: [], + stop: null, }; const FIXTURE = structuredClone(ARTIFACTS) as unknown as ArtifactsStatus; diff --git a/web/src/server/state.test.ts b/web/src/server/state.test.ts index f730fe45..634b86b7 100644 --- a/web/src/server/state.test.ts +++ b/web/src/server/state.test.ts @@ -5,7 +5,7 @@ import type { ServerStatus } from '../api/generated/ServerStatus'; import { DEFAULT_LAUNCH } from '../api/launch'; import { ARTIFACTS } from '../artifacts/fixtures'; import { en } from '../i18n/en'; -import { blocked, buildFact, causeText, commandLine, hangAdvice } from './state'; +import { blocked, buildFact, causeText, commandLine, hangAdvice, waitedFor } from './state'; const status = (overrides: Partial): ServerStatus => ({ state: 'stopped', @@ -21,6 +21,8 @@ const status = (overrides: Partial): ServerStatus => ({ name: null, port: null, start: null, + stopHolders: [], + stop: null, ...overrides, }); @@ -79,6 +81,27 @@ describe('commandLine', () => { }); }); +/** A stop that waits for `holding`. */ +const stop = (holding: string[]) => ({ + since: '2026-10-28T14:00:00Z', + limitAt: '2026-10-28T14:01:00Z', + holding, + released: [], +}); + +describe('waitedFor', () => { + it('should count the resources a stop waits for, and say nothing of a stop that waits for none', () => { + const stopping = (holding: string[] | null) => + status({ state: 'stopping', stop: holding === null ? null : stop(holding) }); + + expect(waitedFor(en, stopping(['qb-inventory']))).toBe('waiting for 1 resource'); + expect(waitedFor(en, stopping(['esx_vehicleshop', 'qb-inventory']))).toBe('waiting for 2 resources'); + expect(waitedFor(en, stopping([]))).toBeNull(); + expect(waitedFor(en, stopping(null))).toBeNull(); + expect(waitedFor(en, status({ state: 'online', stopHolders: ['qb-inventory'] }))).toBeNull(); + }); +}); + describe('causeText', () => { it('should word who asked by what the server does now', () => { const by = { kind: 'requested', by: 'ada' } as const; diff --git a/web/src/server/state.ts b/web/src/server/state.ts index c4f5bd6e..eec0d1a6 100644 --- a/web/src/server/state.ts +++ b/web/src/server/state.ts @@ -90,6 +90,12 @@ export const causeText = (t: Messages, status: ServerStatus): string | null => { } }; +/** How many resources the stop under way waits for, or null when it waits for none. */ +export const waitedFor = (t: Messages, status: ServerStatus): string | null => { + const holding = status.state === 'stopping' ? (status.stop?.holding.length ?? 0) : 0; + return holding === 0 ? null : t.status.waitingFor(holding); +}; + /** * What a hang verdict leaves the owner, who alone reads the launch settings: the delay that ran * out and where it is set. A first start that builds caches stays silent past the default, and diff --git a/web/src/settings/Launch.test.tsx b/web/src/settings/Launch.test.tsx index 2c6bc556..985e7dc2 100644 --- a/web/src/settings/Launch.test.tsx +++ b/web/src/settings/Launch.test.tsx @@ -312,6 +312,68 @@ describe('Launch settings', () => { expect(queryByText(en.server.problems.outOfRange)).toBeNull(); }); + it('should save the wait at a stop in seconds, and say it applies from the next stop', async () => { + const fetch = vi.fn(async () => Response.json(stored('server.cfg', 2))); + vi.stubGlobal('fetch', fetch); + const { getByText } = await page(stored('server.cfg', 1)); + const hold = input(items.stopHold.label); + expect(hold.value).toBe('60'); + + fireEvent.change(hold, { target: { value: '120' } }); + getByText(bar.changes(1)); + getByText(`· ${bar.applies([en.settings.appliesWhen.now])}`); + fireEvent.click(getByText(bar.save)); + + await waitFor(() => getByText(en.server.savedParts(['stopHold']))); + expect(saved(fetch)).toEqual({ + settings: { ...stored('server.cfg', 1).settings, stopHoldSeconds: 120 }, + version: 1, + }); + }); + + it('should say what each kind of setting applies from when a save changes the wait with others', async () => { + vi.stubGlobal( + 'fetch', + vi.fn(async () => Response.json(stored('configs/live.cfg', 2))), + ); + const { getByText } = await page(stored('server.cfg', 1)); + + fireEvent.change(input(items.cfgFile.label), { target: { value: 'configs/live.cfg' } }); + fireEvent.change(input(items.hangTimeout.label), { target: { value: '15' } }); + fireEvent.change(input(items.stopHold.label), { target: { value: '30' } }); + fireEvent.click(getByText(bar.save)); + + await waitFor(() => + getByText( + 'Saved. Hang detection applies at once, to a running server too; the wait for resources ' + + 'applies from the next stop; the other settings apply from the next start of FXServer, ' + + 'a restart after a crash included.', + ), + ); + }); + + it('should refuse a wait that is not 5 to 600 whole seconds next to its field, without sending it', async () => { + const fetch = vi.fn(); + vi.stubGlobal('fetch', fetch); + Element.prototype.scrollIntoView = vi.fn(); + const { getByText, queryByText } = await page(stored('server.cfg', 1)); + const hold = input(items.stopHold.label); + + for (const typed of ['4', '601', '7.5', '']) { + fireEvent.change(hold, { target: { value: typed } }); + expect(queryByText(en.settings.launch.stopHoldRange)).toBeNull(); + fireEvent.click(getByText(bar.save)); + + getByText(en.settings.launch.stopHoldRange); + expect(hold.getAttribute('aria-invalid')).toBe('true'); + expect(document.activeElement).toBe(hold); + } + expect(saved(fetch)).toBeUndefined(); + expect(queryByText(en.server.problems.outOfRange)).toBeNull(); + fireEvent.change(hold, { target: { value: '5' } }); + expect(queryByText(en.settings.launch.stopHoldRange)).toBeNull(); + }); + it('should put each refused argument message under its own field, and the keyboard on the first', async () => { const refusal = { code: 'invalid_launch_settings', diff --git a/web/src/settings/Launch.tsx b/web/src/settings/Launch.tsx index 71a685cd..fdd1920a 100644 --- a/web/src/settings/Launch.tsx +++ b/web/src/settings/Launch.tsx @@ -20,6 +20,7 @@ import { launchIssues, launchQuery, saveLaunch, + STOP_HOLD_RANGE, } from '../api/launch'; import { useArtifacts } from '../artifacts/context'; import { Button, buttonVariants } from '../components/Button'; @@ -30,6 +31,8 @@ import type { Messages } from '../i18n/en'; import { errorMessage } from '../i18n/errors'; import { useI18n } from '../i18n/I18nProvider'; import { cn } from '../lib/cn'; +import { useServerStatus } from '../server/context'; +import { isRunning } from '../server/state'; import { anchorOf, type SettingId } from './catalog'; import { CfgConflict, CfgOnly, ConvarFacts, ConvarNames, ConvarValues, useConvars } from './Convars'; import { keyboardLeft, SettingsForm, useSection } from './Form'; @@ -52,6 +55,7 @@ const SETTING_OF = { extraArguments: 'extraArguments', hangDetection: 'hangDetection', hangTimeoutSeconds: 'hangTimeout', + stopHoldSeconds: 'stopHold', } satisfies Record; let lastRow = 0; @@ -72,14 +76,34 @@ const minutesFit = (minutes: string) => { return minutes.trim() !== '' && Number.isInteger(value) && value >= 1 && value <= 60; }; -/** What a save says: hang detection reaches a running server at once, the rest its next start. */ +/** The seconds typed for the wait at a stop, as they are sent: NaN for a blank field. */ +const holdOf = (seconds: string) => (seconds.trim() === '' ? Number.NaN : Number(seconds)); +/** A whole number of seconds within what Observer takes. */ +const holdFits = (seconds: string) => { + const value = holdOf(seconds); + return Number.isInteger(value) && value >= STOP_HOLD_RANGE.min && value <= STOP_HOLD_RANGE.max; +}; + +/** + * What a save says: hang detection reaches a running server at once, the wait at a stop its next + * stop, the rest its next start. + */ const savedMessage = (t: Messages, before: Settings, after: Settings) => { const changed = changedSettings(before, after); const hang = changed.some((key) => HANG_SETTINGS.has(key)); + const hold = changed.includes('stopHoldSeconds'); + const rest = changed.some((key) => !HANG_SETTINGS.has(key) && key !== 'stopHoldSeconds'); + if (hold) { + return t.server.savedParts([ + ...(hang ? (['hang'] as const) : []), + 'stopHold', + ...(rest ? (['rest'] as const) : []), + ]); + } if (!hang) { return t.server.saved; } - return changed.every((key) => HANG_SETTINGS.has(key)) ? t.server.savedHang : t.server.savedBoth; + return rest ? t.server.savedBoth : t.server.savedHang; }; /** How Observer starts FXServer, the owner's: what was the Server page. */ @@ -131,6 +155,8 @@ function LaunchForm({ saved }: { saved: StoredLaunch | null }) { const [fields, setFields] = useState(baseline); const [rows, setRows] = useState(() => toRows(baseline)); const [minutes, setMinutes] = useState(() => minutesOf(baseline)); + const [hold, setHold] = useState(() => String(baseline.stopHoldSeconds)); + const { status } = useServerStatus(); const [issues, setIssues] = useState([]); const [outcome, setOutcome] = useState(null); const notice = useRef(null); @@ -161,6 +187,7 @@ function LaunchForm({ saved }: { saved: StoredLaunch | null }) { // so one the field cannot show exactly is never an unsaved change nobody made. hangTimeoutSeconds: minutes === minutesOf(baseline) ? baseline.hangTimeoutSeconds : secondsOf(minutes), + stopHoldSeconds: hold === String(baseline.stopHoldSeconds) ? baseline.stopHoldSeconds : holdOf(hold), }; const changed = changedSettings(baseline, draft); const stale = (saved?.version ?? null) !== (shown?.version ?? null); @@ -170,6 +197,7 @@ function LaunchForm({ saved }: { saved: StoredLaunch | null }) { setShown(stored); setFields(settings); setMinutes(minutesOf(settings)); + setHold(String(settings.stopHoldSeconds)); // Rows keep their ids by position, so their inputs, and the keyboard in one, stay put. setRows((current) => settings.extraArguments.map((argument, index) => ({ @@ -245,11 +273,15 @@ function LaunchForm({ saved }: { saved: StoredLaunch | null }) { setOutcome(null); // A fraction or an emptied field would be refused as a malformed request rather than // next to its field: it is checked before sending. - if (!minutesFit(minutes)) { + const unfit: LaunchField[] = [ + ...(minutesFit(minutes) ? [] : (['hangTimeoutSeconds'] as const)), + ...(holdFits(hold) ? [] : (['stopHoldSeconds'] as const)), + ]; + if (unfit.length > 0) { showFirstIssue.current = true; setIssues((current) => [ - ...current.filter((each) => each.field !== 'hangTimeoutSeconds'), - { field: 'hangTimeoutSeconds', index: null, problem: 'outOfRange' }, + ...current.filter((each) => !unfit.includes(each.field)), + ...unfit.map((field) => ({ field, index: null, problem: 'outOfRange' as const })), ]); return; } @@ -410,6 +442,44 @@ function LaunchForm({ saved }: { saved: StoredLaunch | null }) { + + + {(ids) => { + const problem = issue('stopHoldSeconds') && words.stopHoldRange; + const holders = + status !== null && isRunning(status.state) ? status.stopHolders : null; + return ( + <> + { + setHold(event.target.value); + setOutcome(null); + forget('stopHoldSeconds'); + }} + /> + {problem && {problem}} + {holders !== null && ( +

+ {holders.length > 0 ? words.heldBy(holders) : words.heldByNone} +

+ )} + + ); + }} + + +

+ )} + + {quit.isError && ( +

+ {t.controls.failed(t.controls.quitNow, errorMessage(t, quit.error))} +

+ )} + + {confirming && ( + setConfirming(false)} + footer={ + <> + + + + } + > +

{t.controls.quitNowBody(stop.holding)}

+

{t.controls.quitNowAudit}

+ + )} + + ); +} diff --git a/web/src/shell/StatusBar.tsx b/web/src/shell/StatusBar.tsx index 2c3c8cfb..b820926c 100644 --- a/web/src/shell/StatusBar.tsx +++ b/web/src/shell/StatusBar.tsx @@ -10,7 +10,7 @@ import { useArtifacts } from '../artifacts/context'; import { useSchedule } from '../schedule/context'; import { startTotal } from '../overview/StartCard'; import { useServerStatus } from '../server/context'; -import { STATE_INK, STATE_LED, isRunning } from '../server/state'; +import { STATE_INK, STATE_LED, isRunning, waitedFor } from '../server/state'; export const LINK_LED = { connecting: 'led-pending', @@ -52,7 +52,11 @@ export function StatusBar() { } else if (status !== null && isRunning(status.state) && status.startedAt !== null) { lasted = t.status.upFor(format.duration(secondsSince(status.startedAt, now))); } else if (status !== null && !isRunning(status.state)) { - lasted = t.status.forTime(format.duration(secondsSince(status.since, now))); + const waiting = waitedFor(t, status); + lasted = [ + t.status.forTime(format.duration(secondsSince(status.since, now))), + ...(waiting === null ? [] : [waiting]), + ].join(' · '); } return ( diff --git a/web/src/styles/shell.css b/web/src/styles/shell.css index d8ff84e3..05919587 100644 --- a/web/src/styles/shell.css +++ b/web/src/styles/shell.css @@ -351,7 +351,8 @@ min-width: 0; margin-left: auto; } - .controls-failure { + .controls-failure, + .controls-hold { flex-basis: 100%; }