diff --git a/.github/workflows/integration.yml b/.github/workflows/integration.yml index 7fd08685e..292d16e80 100644 --- a/.github/workflows/integration.yml +++ b/.github/workflows/integration.yml @@ -183,8 +183,9 @@ jobs: - name: Build release (SQLite backend) run: cargo build --release -p extenddb --no-default-features --features sqlite - # The migration lock between serve and migrate, on a catalog of its own - # (port 18450), before the suite's server starts. + # The migration lock between serve and migrate, on a catalog of its own, + # before the suite's server starts. The script serves on ports 18450 and + # 18451; the next step uses 18451 after this one has ended. - name: Check serve and migrate on one catalog run: devtools/check-sqlite-catalog-lock ./target/release/extenddb 18450 @@ -516,6 +517,7 @@ jobs: cargo test --release -p extenddb-storage-postgres --test migrations_fresh --test migrations_released --test migrations_crash --test migrations_golden --test migrations_guards --test migrations_runs + --test migrations_startup # The daemonized server logs to syslog; dump it so server-side failures # are diagnosable from the job log. diff --git a/.github/workflows/launcher.yml b/.github/workflows/launcher.yml index b302f2690..f48a69817 100644 --- a/.github/workflows/launcher.yml +++ b/.github/workflows/launcher.yml @@ -45,3 +45,4 @@ jobs: set -euo pipefail cd packaging/npm node test/launcher.test.js + node test/start.test.js diff --git a/.github/workflows/npm-build-matrix.yml b/.github/workflows/npm-build-matrix.yml index 4fe10801f..b562b4019 100644 --- a/.github/workflows/npm-build-matrix.yml +++ b/.github/workflows/npm-build-matrix.yml @@ -163,6 +163,7 @@ jobs: set -euo pipefail cd packaging/npm node test/launcher.test.js + node test/start.test.js - name: Portability gate - the binary must run on the oldest libc we support if: contains(matrix.target, 'musl') diff --git a/crates/app/src/cmd_migrate_runner.rs b/crates/app/src/cmd_migrate_runner.rs index ec4d4f35f..5e7e1dab8 100644 --- a/crates/app/src/cmd_migrate_runner.rs +++ b/crates/app/src/cmd_migrate_runner.rs @@ -22,8 +22,8 @@ use extenddb_config as config; use extenddb_storage::migrations::advice::{self, Advice, AdviceFor}; use extenddb_storage::migrations::{ AdminRole, CatalogMigrations, CatalogStatus, Listed, MigrationError, MigrationId, Pending, - RunKind, RunReport, Target, before_lock, behind_line, exit, forget_locked, run_locked, - stores_behind, + RunKind, RunReport, Target, WhenCurrent, before_lock, behind_line, exit, forget_locked, + run_with_lock, stores_behind, }; use crate::cmd_migrate::MigrateArgs; @@ -305,17 +305,25 @@ async fn apply( kind: RunKind, lock_timeout: Duration, ) -> Result { - for note in before_lock(migrations, target, kind).await? { + for note in before_lock(migrations, target, kind, "migrate --yes").await? { println!("Note: {}", note.text); } println!( "--- Taking the migration lock (waiting up to {} s for a server or another migration)...", lock_timeout.as_secs() ); - let lock = migrations.lock(target, lock_timeout).await?; - let report = run_locked(migrations, target, &lock, release, kind).await; - migrations.release(lock).await; - let report = report?; + // On a current catalog the backend's run still goes ahead: it makes the + // steps the backend takes beside the ledger (PostgreSQL's pgvector + // attempt), which an operator who installs pgvector later relies on. + let report = run_with_lock( + migrations, + target, + release, + kind, + lock_timeout, + WhenCurrent::Run, + ) + .await?; print_report(&report, kind); if report.applied.is_empty() && kind == RunKind::Migrate { // A catalog ahead by additive migrations has nothing to apply and diff --git a/crates/app/src/cmd_migrate_runner_tests.rs b/crates/app/src/cmd_migrate_runner_tests.rs index feed9cb4a..2e3534674 100644 --- a/crates/app/src/cmd_migrate_runner_tests.rs +++ b/crates/app/src/cmd_migrate_runner_tests.rs @@ -100,6 +100,7 @@ const ADVICE: Advice<'static> = Advice { backup: "back up db", config: Some("extenddb.toml"), assignment: None, + serving: false, }; fn behind() -> CatalogStatus { diff --git a/crates/app/src/cmd_serve.rs b/crates/app/src/cmd_serve.rs index a754aa4c2..4a82019c5 100755 --- a/crates/app/src/cmd_serve.rs +++ b/crates/app/src/cmd_serve.rs @@ -46,11 +46,24 @@ pub struct ServeArgs { /// always writes one. #[arg(long)] write_pid_file: bool, + + /// Apply the catalog's pending migrations before serving, for this run + /// only, as `[server] catalog_upgrade = "apply"` does. + /// + /// The server takes the migration lock, waiting up to + /// `catalog_upgrade_lock_timeout` seconds (60 by default) for another + /// migration or a running server, and exits 6 if it is not free in time. + /// A catalog that needs a person, or that this binary cannot use, is + /// refused as without the flag. + #[arg(long)] + migrate: bool, } -/// Bind the listening socket, daemonize, then start the tokio runtime. -/// Binding before forking ensures port conflicts are reported to stderr -/// before the parent process exits (D-4). +/// Check the catalog, bind the listening socket, daemonize, then start the +/// tokio runtime. The catalog check comes first, so the port accepts no +/// connection while the catalog migrates; binding before forking ensures +/// port conflicts are reported to stderr before the parent process exits +/// (D-4). pub fn run(args: &ServeArgs, build: BuildInfo) -> anyhow::Result<()> { // Load config early so bind address is known before fork. A dev-mode // build serves with built-in defaults when no config file exists @@ -94,12 +107,27 @@ pub fn run(args: &ServeArgs, build: BuildInfo) -> anyhow::Result<()> { ); } + crate::serve_catalog::lock_timeout(&app_config.server)?; + // Fail fast, before binding the port, when no backend is installed. let backend = &app_config.storage.backend; extenddb_storage::backend_name() .ok_or_else(|| anyhow::anyhow!("no storage backend installed"))?; let catalog_version = extenddb_storage::migrations::binary_catalog_label(); + // Daemon mode (double fork, PID file, syslog) is POSIX-only. On Windows + // the server must be run with `--foreground` under an external + // supervisor (a terminal, a service wrapper, or the npm launcher, which + // always passes `--foreground`). Refused before the catalog is read, so + // a server that cannot start migrates nothing. + #[cfg(not(unix))] + if !args.foreground { + anyhow::bail!( + "daemon mode is not supported on this platform; \ + run `extenddb serve --foreground`" + ); + } + let port = args.port.unwrap_or(app_config.server.port); // Dev mode serves plain HTTP with relaxed authorization; confine it to @@ -141,6 +169,23 @@ pub fn run(args: &ServeArgs, build: BuildInfo) -> anyhow::Result<()> { let bind_addr = format!("{}:{}", app_config.server.bind_addr, port); + // The catalog's status, and under `apply` its migrations: before the + // port is bound, so the port accepts no connection while the catalog + // migrates, and before the fork, so that in daemon mode a refusal's exit + // code and message reach the invoking shell. The server checks the + // catalog again when it registers. + let code = crate::serve_catalog::check_catalog(&crate::serve_catalog::ServeStart { + server: &app_config.server, + location: app_config.storage.connection_config(), + migrate: args.migrate, + release: build.version, + config_file: config_exists.then_some(args.config.as_str()), + daemonizes: !args.foreground, + })?; + if code != extenddb_storage::migrations::exit::OK { + std::process::exit(i32::from(code)); + } + // Bind in sync context — errors go to stderr before daemonizing. let std_listener = TcpListener::bind(&bind_addr) .map_err(|e| anyhow::anyhow!("Failed to bind {bind_addr}: {e}"))?; @@ -213,16 +258,7 @@ pub fn run(args: &ServeArgs, build: BuildInfo) -> anyhow::Result<()> { // can be supervised by Docker, Kubernetes, systemd Type=simple, etc. // Graceful shutdown on SIGINT/SIGTERM still works. if !args.foreground { - // Daemon mode (double fork, PID file, syslog) is POSIX-only. On - // Windows the server must be run with `--foreground` under an - // external supervisor (a terminal, a service wrapper, or the npm - // launcher, which always passes `--foreground`). - #[cfg(not(unix))] - anyhow::bail!( - "daemon mode is not supported on this platform; \ - run `extenddb serve --foreground`" - ); - + // Daemon mode is POSIX-only; other platforms were refused above. #[cfg(unix)] { let pid_file = pid_file @@ -450,6 +486,16 @@ mod tests { assert!(args.foreground); } + /// `--migrate` applies the catalog's pending migrations for this run; + /// without it the server follows `[server] catalog_upgrade`. + #[test] + fn migrate_flag_is_recognized_and_off_by_default() { + assert!(!parse(&["extenddb-serve"]).migrate); + let args = parse(&["extenddb-serve", "--migrate", "--foreground"]); + assert!(args.migrate); + assert!(args.foreground); + } + #[test] fn no_daemon_alias_is_recognized() { // The issue proposed either `--foreground` or `--no-daemon`; make diff --git a/crates/app/src/init_helpers.rs b/crates/app/src/init_helpers.rs index 15e700f3f..61473b7ed 100755 --- a/crates/app/src/init_helpers.rs +++ b/crates/app/src/init_helpers.rs @@ -212,6 +212,10 @@ pub(crate) fn generate_config( let tls_cert = extenddb_config::expand_tilde("~/.extenddb/tls/cert.pem"); let tls_key = extenddb_config::expand_tilde("~/.extenddb/tls/key.pem"); let run_dir = extenddb_config::expand_tilde("~/.extenddb/run"); + // `refuse`, or `apply` in a dev build. + let catalog_upgrade = extenddb_config::ServerConfig::default() + .catalog_upgrade + .as_str(); // Compute docs_dir line before the template so it lands in the top-level // TOML section (before any [section] header). @@ -250,6 +254,8 @@ bind_addr = "{bind_addr}" # region = "us-east-1" # AWS region for ARN generation # run_dir = "{run_dir}" # Directory for PID file # throttling_enabled = false # Enable provisioned throughput throttling +# catalog_upgrade = "{catalog_upgrade}" # "apply" migrates a catalog behind this binary at startup +# catalog_upgrade_lock_timeout = 60 # Seconds serve waits for the migration lock under "apply" [server.tls] # TLS is mandatory. The server refuses to start with enabled = false. diff --git a/crates/app/src/lib.rs b/crates/app/src/lib.rs index 157f29d9b..19c28b73a 100644 --- a/crates/app/src/lib.rs +++ b/crates/app/src/lib.rs @@ -37,6 +37,7 @@ mod cmd_verify; mod init_helpers; mod manage_http; mod manage_types; +mod serve_catalog; mod serve_helpers; mod util; diff --git a/crates/app/src/serve_catalog.rs b/crates/app/src/serve_catalog.rs new file mode 100644 index 000000000..f2a42a7a5 --- /dev/null +++ b/crates/app/src/serve_catalog.rs @@ -0,0 +1,174 @@ +// Copyright 2026 ExtendDB contributors +// SPDX-License-Identifier: Apache-2.0 + +//! The catalog check `extenddb serve` makes before it binds its port and +//! daemonizes: the status, read by the startup policy (`[server] +//! catalog_upgrade`, or `--migrate` for one run), and under `apply` the run +//! that migrates a catalog behind this binary. It runs in the invoking +//! process, on a runtime that is shut down before the server forks, so in +//! daemon mode the exit code and the message of a refusal reach the +//! invoking shell as they do in the foreground. The server checks the +//! catalog again when it registers, after the fork. + +use std::time::{Duration, Instant}; + +use extenddb_config::{self as config, CatalogUpgrade, ServerConfig}; +use extenddb_storage::migrations::advice::{self, AdviceFor}; +use extenddb_storage::migrations::{ + CatalogMigrations, Startup, Target, exit, installed, prepare_to_serve, +}; + +/// The start of every line `serve` prints on stderr while it checks and +/// migrates the catalog. The npm launcher's startup timeout restarts at +/// each one. +pub(crate) const PROGRESS_PREFIX: &str = "catalog migration: "; + +/// How long the check's runtime may take to stop. A blocking thread still +/// running after it keeps a daemon from forking. +const SHUTDOWN_CAP: Duration = Duration::from_secs(10); + +/// How `serve` was started, as the catalog check reads it. +pub(crate) struct ServeStart<'a> { + /// The `[server]` section: `catalog_upgrade` and its lock timeout. + pub(crate) server: &'a ServerConfig, + /// The storage location the config gives. + pub(crate) location: &'a str, + /// `serve --migrate`, which sets `catalog_upgrade = "apply"` for this + /// run. + pub(crate) migrate: bool, + /// The ExtendDB release, recorded in the ledger rows a run writes. + pub(crate) release: &'a str, + /// The config file the server was started with, named in the command a + /// refusal prints. + pub(crate) config_file: Option<&'a str>, + /// Whether the server forks once the check has passed (daemon mode). + pub(crate) daemonizes: bool, +} + +/// `[server] catalog_upgrade_lock_timeout`, refused above a day. +/// +/// # Errors +/// +/// The timeout is above a day. +pub(crate) fn lock_timeout(server: &ServerConfig) -> anyhow::Result { + let secs = server.catalog_upgrade_lock_timeout; + if secs > config::MAX_CATALOG_UPGRADE_LOCK_TIMEOUT { + anyhow::bail!( + "server.catalog_upgrade_lock_timeout is {secs} s; it may be at most {} s (a day)", + config::MAX_CATALOG_UPGRADE_LOCK_TIMEOUT + ); + } + Ok(Duration::from_secs(secs)) +} + +/// Check the catalog `start` names before the server binds its port, +/// printing on stderr the lines of the check and of a run, and any +/// refusal. Returns the exit code: 0 when the server may start, else the +/// code `serve` exits with. +/// +/// The warnings the backends log during the check, such as PostgreSQL's +/// retries after a lock timeout, go to stderr through a subscriber set for +/// the check alone, as `migrate --yes` prints them. The global default stays +/// free for the server's own subscriber. +/// +/// # Errors +/// +/// The lock timeout is above a day, or the runtime could not be built. +pub(crate) fn check_catalog(start: &ServeStart<'_>) -> anyhow::Result { + let Some(migrations) = installed() else { + return Ok(exit::OK); + }; + let subscriber = tracing_subscriber::fmt() + .with_writer(std::io::stderr) + .finish(); + tracing::subscriber::with_default(subscriber, || { + check(migrations, start, SHUTDOWN_CAP, &|line| eprintln!("{line}")) + }) +} + +/// [`check_catalog`] on `migrations`, writing each line to `out`, with +/// `shutdown_cap` for the check's runtime to stop. +fn check( + migrations: &dyn CatalogMigrations, + start: &ServeStart<'_>, + shutdown_cap: Duration, + out: &(dyn Fn(&str) + Send + Sync), +) -> anyhow::Result { + let upgrade = if start.migrate { + CatalogUpgrade::Apply + } else { + start.server.catalog_upgrade + }; + let target = Target::at(start.location); + let startup = Startup { + apply: upgrade == CatalogUpgrade::Apply, + // A dev build's server creates its catalog in a missing or empty + // database file. + creates_uninitialized: cfg!(feature = "dev-mode"), + release: start.release, + lock_timeout: lock_timeout(start.server)?, + heartbeat: Startup::HEARTBEAT, + }; + let runtime = tokio::runtime::Builder::new_current_thread() + .enable_all() + .build()?; + // Each line of a progress message gets the prefix, so a note that spans + // several lines counts as progress to the launcher on each of them. + let progress = |text: &str| { + for line in text.lines() { + out(&format!("{PROGRESS_PREFIX}{line}")); + } + }; + let result = runtime.block_on(prepare_to_serve(migrations, &target, &startup, &progress)); + let capped = shut_down(runtime, shutdown_cap); + match result { + Ok(prepared) => { + if let Some(warning) = prepared.warning { + out(&format!("WARNING: {warning}")); + } + if capped && start.daemonizes { + out(&format!( + "Error: a blocking thread of the catalog check, such as a host name lookup, \ + was still running {} s after the check ended. The server does not fork \ + while it runs, since a lock that thread holds would stay held in the \ + child, where the thread does not exist. Run extenddb serve again, or with \ + --foreground.", + shutdown_cap.as_secs() + )); + return Ok(exit::ERROR); + } + Ok(exit::OK) + } + Err(error) => { + let advice = AdviceFor::new( + start.release, + config::redact_password(start.location), + Some(migrations), + &target, + start.config_file, + ) + .for_server(); + out(&format!( + "Error: {}", + advice::error_message(&error, &advice.advice()) + )); + // A refusal never lets the server start, whatever its status's + // code. + Ok(error.exit_code().max(exit::ERROR)) + } + } +} + +/// Shut `runtime` down, waiting up to `cap` for its tasks and blocking +/// threads to end. `true` when the wait reached the cap, so a blocking +/// thread may still be running: a fork copies only the thread that calls +/// it, and a lock such a thread holds would stay held in the child. +fn shut_down(runtime: tokio::runtime::Runtime, cap: Duration) -> bool { + let started = Instant::now(); + runtime.shutdown_timeout(cap); + started.elapsed() >= cap +} + +#[cfg(test)] +#[path = "serve_catalog_tests.rs"] +mod tests; diff --git a/crates/app/src/serve_catalog_tests.rs b/crates/app/src/serve_catalog_tests.rs new file mode 100644 index 000000000..9cc7315a7 --- /dev/null +++ b/crates/app/src/serve_catalog_tests.rs @@ -0,0 +1,328 @@ +// Copyright 2026 ExtendDB contributors +// SPDX-License-Identifier: Apache-2.0 + +//! The catalog check `serve` makes before it binds its port: `--migrate` +//! over `[server] catalog_upgrade`, the prefix on every line it prints, the +//! exit code of a refusal, the lock timeout's bound, and a runtime that +//! does not stop in time before a fork. + +use std::collections::VecDeque; +use std::sync::Mutex; +use std::time::Duration; + +use async_trait::async_trait; +use extenddb_config::{CatalogUpgrade, ServerConfig}; +use extenddb_storage::migrations::{ + AppliedStep, CatalogMigrations, CatalogStatus, HeldLock, Kind, LedgerRow, Listed, + MigrationError, MigrationId, Pending, RunKind, RunReport, StoreKind, Target, exit, +}; + +use super::{PROGRESS_PREFIX, ServeStart, check, lock_timeout}; + +/// The cap the tests give the check's runtime to stop. +const CAP: Duration = Duration::from_secs(10); + +struct Fake { + /// What the next status reads return, the last one repeated. + statuses: Mutex>>, + lock: Result<(), MigrationError>, + report: RunReport, + /// A blocking thread the run starts and does not wait for sleeps this + /// long. + leaves_thread: Option, + calls: Mutex>, +} + +impl Fake { + fn new(statuses: Vec>) -> Self { + Self { + statuses: Mutex::new(statuses.into()), + lock: Ok(()), + report: applied_report(), + leaves_thread: None, + calls: Mutex::new(Vec::new()), + } + } + + fn calls(&self) -> Vec<&'static str> { + self.calls.lock().unwrap().clone() + } + + fn call(&self, name: &'static str) { + self.calls.lock().unwrap().push(name); + } +} + +#[async_trait] +impl CatalogMigrations for Fake { + fn listed(&self, _id: MigrationId) -> Listed { + Listed::NotApplicable("fake") + } + fn backup_advice(&self, target: &Target) -> String { + format!("back up {}", target.location) + } + async fn status(&self, _target: &Target) -> Result { + self.call("status"); + let mut statuses = self.statuses.lock().unwrap(); + let status = statuses.front().cloned().expect("a status"); + if statuses.len() > 1 { + statuses.pop_front(); + } + status + } + async fn catalog_ledger(&self, _: &Target) -> Result, MigrationError> { + Ok(Vec::new()) + } + async fn lock(&self, target: &Target, _: Duration) -> Result { + self.call("lock"); + self.lock + .clone() + .map(|()| HeldLock::new(target.location.as_str(), ())) + } + async fn run( + &self, + _lock: &HeldLock, + _release: &str, + _kind: RunKind, + ) -> Result { + self.call("run"); + if let Some(sleep) = self.leaves_thread { + drop(tokio::task::spawn_blocking(move || { + std::thread::sleep(sleep) + })); + } + Ok(self.report.clone()) + } + async fn forget(&self, _lock: &HeldLock, _id: u32) -> Result<(), MigrationError> { + unreachable!("a server forgets nothing") + } + async fn release(&self, lock: HeldLock) { + self.call("release"); + drop(lock); + } +} + +fn behind() -> CatalogStatus { + CatalogStatus::Behind { + version: Some(1), + pending: MigrationId::ALL + .iter() + .skip(1) + .map(|id| Pending { + id: id.number(), + name: id.name(), + store: StoreKind::Catalog, + store_name: "db".to_owned(), + kind: Kind::Breaking, + }) + .collect(), + } +} + +/// A run's report whose copy note spans two lines. +fn applied_report() -> RunReport { + RunReport { + from: Some(1), + to: Some(MigrationId::LATEST.number()), + applied: MigrationId::ALL + .iter() + .skip(1) + .map(|id| AppliedStep { + id: id.number(), + name: id.name(), + store_name: "db".to_owned(), + outcome: extenddb_storage::migrations::Outcome::Applied, + notes: vec!["a note\nthat spans two lines".to_owned()], + }) + .collect(), + notes: vec!["copied the database to db.pre-migration-1-to-4-x".to_owned()], + } +} + +fn server(upgrade: CatalogUpgrade) -> ServerConfig { + ServerConfig { + catalog_upgrade: upgrade, + catalog_upgrade_lock_timeout: 1, + ..ServerConfig::default() + } +} + +fn start(server: &ServerConfig, migrate: bool, daemonizes: bool) -> ServeStart<'_> { + ServeStart { + server, + location: "db", + migrate, + release: "1.0.0-test", + config_file: Some("/etc/extenddb/extenddb.toml"), + daemonizes, + } +} + +/// Run the check, returning its exit code and every line it printed, one +/// entry per line. +fn run_check(fake: &Fake, start: &ServeStart<'_>, cap: Duration) -> (u8, Vec) { + let printed = Mutex::new(Vec::new()); + let code = check(fake, start, cap, &|text| { + printed.lock().unwrap().push(text.to_owned()); + }) + .expect("the check runs"); + let lines = printed + .into_inner() + .unwrap() + .iter() + .flat_map(|text| text.lines().map(str::to_owned).collect::>()) + .collect(); + (code, lines) +} + +/// The launcher matches this string at the start of a line and restarts +/// its startup timeout at each line that has it: `PROGRESS_PREFIX` in +/// packaging/npm/startup.js, and the copy in its test server, must change +/// with this one. +#[test] +fn the_prefix_is_the_one_the_npm_launcher_matches() { + assert_eq!(PROGRESS_PREFIX, "catalog migration: "); +} + +/// `--migrate` applies a catalog behind this binary for one run under +/// `catalog_upgrade = "refuse"`, which without it exits 3 and takes no +/// lock; `catalog_upgrade = "apply"` applies it without the flag. +#[test] +fn migrate_applies_a_catalog_behind_for_one_run() { + let refuse = server(CatalogUpgrade::Refuse); + let fake = Fake::new(vec![Ok(behind())]); + let (code, _) = run_check(&fake, &start(&refuse, false, false), CAP); + assert_eq!(code, exit::PENDING); + assert_eq!(fake.calls(), ["status"]); + + let fake = Fake::new(vec![Ok(behind())]); + let (code, lines) = run_check(&fake, &start(&refuse, true, false), CAP); + assert_eq!(code, exit::OK, "{lines:?}"); + assert_eq!(fake.calls(), ["status", "lock", "status", "run", "release"]); + + let apply = server(CatalogUpgrade::Apply); + let fake = Fake::new(vec![Ok(behind())]); + let (code, lines) = run_check(&fake, &start(&apply, false, false), CAP); + assert_eq!(code, exit::OK, "{lines:?}"); + assert!(fake.calls().contains(&"run"), "{:?}", fake.calls()); +} + +/// Every line a run prints starts with the prefix, the lines of a note that +/// spans several included, so the launcher counts each of them. +#[test] +fn every_progress_line_starts_with_the_prefix() { + let refuse = server(CatalogUpgrade::Refuse); + let fake = Fake::new(vec![Ok(behind())]); + let (code, lines) = run_check(&fake, &start(&refuse, true, false), CAP); + assert_eq!(code, exit::OK, "{lines:?}"); + assert_eq!(lines[0], "catalog migration: reading the catalog status"); + assert!( + lines.contains(&"catalog migration: that spans two lines".to_owned()), + "{lines:?}" + ); + for line in &lines { + assert!(line.starts_with(PROGRESS_PREFIX), "{line:?} in {lines:?}"); + } +} + +/// A refusal prints its message on stderr and exits with its status's +/// code, and never with 0: an error whose code would be 0 exits 1. +#[test] +fn a_refusal_exits_with_its_code_and_never_with_0() { + let refuse = server(CatalogUpgrade::Refuse); + let cases = [ + (Ok(behind()), exit::PENDING), + ( + Ok(CatalogStatus::NeedsAttention { + items: vec!["migration 2: a collision".to_owned()], + }), + exit::ATTENTION, + ), + ( + Ok(CatalogStatus::AheadIncompatible { + unknown: vec![(MigrationId::LATEST.number() + 1, "later".to_owned())], + }), + exit::AHEAD_INCOMPATIBLE, + ), + ( + Ok(CatalogStatus::Uninitialized), + if cfg!(feature = "dev-mode") { + exit::OK + } else { + exit::ERROR + }, + ), + ( + Err(MigrationError::Status(CatalogStatus::Current { + version: MigrationId::LATEST.number(), + })), + exit::ERROR, + ), + ]; + for (status, code) in cases { + let fake = Fake::new(vec![status.clone()]); + let (got, lines) = run_check(&fake, &start(&refuse, false, false), CAP); + assert_eq!(got, code, "{status:?}: {lines:?}"); + if code != exit::OK { + assert!( + lines.iter().any(|l| l.starts_with("Error: ")), + "{status:?}: {lines:?}" + ); + } + } + + // A lock that stays held: exit 6 once the wait reaches the timeout. + let mut fake = Fake::new(vec![Ok(behind())]); + fake.lock = Err(MigrationError::Locked("another migration holds it".into())); + let (code, lines) = run_check(&fake, &start(&refuse, true, false), CAP); + assert_eq!(code, exit::LOCKED, "{lines:?}"); +} + +/// A blocking thread of the check still running when the runtime's +/// shutdown reaches its cap keeps a daemon from forking: the check prints +/// the cause and exits 1. A foreground server does not fork, and starts. +#[test] +fn a_thread_still_running_after_the_check_keeps_a_daemon_from_forking() { + let refuse = server(CatalogUpgrade::Refuse); + let mut fake = Fake::new(vec![Ok(behind())]); + fake.leaves_thread = Some(Duration::from_millis(500)); + let cap = Duration::from_millis(50); + let (code, lines) = run_check(&fake, &start(&refuse, true, true), cap); + assert_eq!(code, exit::ERROR, "{lines:?}"); + let last = lines.last().expect("a line"); + assert!( + last.starts_with("Error: a blocking thread of the catalog check") + && last.contains("still running"), + "{lines:?}" + ); + + let (code, lines) = run_check(&fake, &start(&refuse, true, false), cap); + assert_eq!(code, exit::OK, "{lines:?}"); + + // A check whose threads end in time forks. + let fake = Fake::new(vec![Ok(behind())]); + let (code, lines) = run_check(&fake, &start(&refuse, true, true), CAP); + assert_eq!(code, exit::OK, "{lines:?}"); +} + +/// `serve` refuses a lock timeout above a day, as `migrate --lock-timeout` +/// does, before anything reads the catalog. +#[test] +fn a_lock_timeout_above_a_day_is_refused() { + let over = ServerConfig { + catalog_upgrade_lock_timeout: 86_401, + ..ServerConfig::default() + }; + let err = lock_timeout(&over).expect_err("above a day"); + assert!(err.to_string().contains("at most 86400 s"), "{err}"); + let day = ServerConfig { + catalog_upgrade_lock_timeout: 86_400, + ..ServerConfig::default() + }; + assert_eq!(lock_timeout(&day).ok(), Some(Duration::from_secs(86_400))); + + let fake = Fake::new(vec![Ok(behind())]); + let refused = check(&fake, &start(&over, true, false), CAP, &|_| {}); + assert!(refused.is_err(), "{refused:?}"); + assert!(fake.calls().is_empty(), "{:?}", fake.calls()); +} diff --git a/crates/config/Cargo.toml b/crates/config/Cargo.toml index 1c2c59ebf..a3776b3ca 100644 --- a/crates/config/Cargo.toml +++ b/crates/config/Cargo.toml @@ -9,7 +9,8 @@ license.workspace = true [features] # Developer mode: `is_tls_enabled` reports plain HTTP regardless of the -# configured TLS state. Enabled only through the app crate's `dev-mode` feature. +# configured TLS state, and `server.catalog_upgrade` defaults to "apply". +# Enabled only through the app crate's `dev-mode` feature. dev-mode = [] [dependencies] diff --git a/crates/config/src/catalog_upgrade.rs b/crates/config/src/catalog_upgrade.rs new file mode 100644 index 000000000..09fc990d8 --- /dev/null +++ b/crates/config/src/catalog_upgrade.rs @@ -0,0 +1,135 @@ +// Copyright 2026 ExtendDB contributors +// SPDX-License-Identifier: Apache-2.0 + +//! `[server] catalog_upgrade` and `catalog_upgrade_lock_timeout`: what +//! `serve` does with a catalog that is behind this binary. + +use serde::Deserialize; + +/// `[server] catalog_upgrade`: what `serve` does with a catalog that is +/// behind this binary. Every other status a server cannot serve is refused +/// under both values. +#[derive(Debug, Clone, Copy, PartialEq, Eq, Deserialize)] +#[serde(rename_all = "lowercase")] +pub enum CatalogUpgrade { + /// Exit 3, printing the pending migrations and the command that + /// applies them. + Refuse, + /// Apply the pending migrations under the migration lock, as + /// `migrate --yes` does, then serve. + Apply, +} + +impl CatalogUpgrade { + /// The value as the config file spells it. + #[must_use] + pub const fn as_str(self) -> &'static str { + match self { + Self::Refuse => "refuse", + Self::Apply => "apply", + } + } +} + +/// The longest `catalog_upgrade_lock_timeout`, a day, as `migrate`'s +/// `--lock-timeout` allows. +pub const MAX_CATALOG_UPGRADE_LOCK_TIMEOUT: u64 = 86_400; + +/// A dev-mode build migrates its database at startup, since the dev image +/// and the npm launcher run no `migrate`; a production build refuses. +pub(crate) fn default_catalog_upgrade() -> CatalogUpgrade { + if cfg!(feature = "dev-mode") { + CatalogUpgrade::Apply + } else { + CatalogUpgrade::Refuse + } +} + +pub(crate) fn default_catalog_upgrade_lock_timeout() -> u64 { + 60 +} + +#[cfg(test)] +mod tests { + use super::*; + use crate::ServerConfig; + + /// `[server]` as `load` reads it: the file's table, then the + /// `EXTENDDB__` variables in `env` over it. The variables are given to + /// the source instead of set in the process, which other tests share. + fn server_from(file: &str, env: &[(&str, &str)]) -> Result { + #[derive(Deserialize)] + struct File { + #[serde(default)] + server: ServerConfig, + } + let vars = env + .iter() + .map(|(k, v)| ((*k).to_owned(), (*v).to_owned())) + .collect(); + config::Config::builder() + .add_source(config::File::from_str(file, config::FileFormat::Toml)) + .add_source( + config::Environment::with_prefix("EXTENDDB") + .separator("__") + .source(Some(vars)), + ) + .build() + .and_then(config::Config::try_deserialize::) + .map(|f| f.server) + .map_err(|e| e.to_string()) + } + + /// A production build refuses a catalog behind it unless told to apply, + /// and waits 60 s for the lock under `apply`; a dev-mode build applies. + #[test] + fn catalog_upgrade_defaults_to_refuse_and_a_60_s_lock_timeout() { + let server = server_from("", &[]).expect("defaults"); + let expected = if cfg!(feature = "dev-mode") { + CatalogUpgrade::Apply + } else { + CatalogUpgrade::Refuse + }; + assert_eq!(server.catalog_upgrade, expected); + assert_eq!(server.catalog_upgrade_lock_timeout, 60); + assert_eq!(ServerConfig::default().catalog_upgrade, expected); + assert_eq!(ServerConfig::default().catalog_upgrade_lock_timeout, 60); + } + + #[test] + fn catalog_upgrade_is_read_from_the_file_and_the_environment() { + let server = server_from( + "[server]\ncatalog_upgrade = \"apply\"\ncatalog_upgrade_lock_timeout = 5\n", + &[], + ) + .expect("file"); + assert_eq!(server.catalog_upgrade, CatalogUpgrade::Apply); + assert_eq!(server.catalog_upgrade_lock_timeout, 5); + // The environment wins over the file, as for every other key. + let server = server_from( + "[server]\ncatalog_upgrade = \"apply\"\n", + &[ + ("EXTENDDB__SERVER__CATALOG_UPGRADE", "refuse"), + ("EXTENDDB__SERVER__CATALOG_UPGRADE_LOCK_TIMEOUT", "120"), + ], + ) + .expect("environment"); + assert_eq!(server.catalog_upgrade, CatalogUpgrade::Refuse); + assert_eq!(server.catalog_upgrade_lock_timeout, 120); + let server = server_from("", &[("EXTENDDB__SERVER__CATALOG_UPGRADE", "apply")]) + .expect("environment alone"); + assert_eq!(server.catalog_upgrade, CatalogUpgrade::Apply); + } + + #[test] + fn catalog_upgrade_refuses_any_other_value() { + let error = + server_from("[server]\ncatalog_upgrade = \"ignore\"\n", &[]).expect_err("not a value"); + assert!(error.contains("ignore"), "{error}"); + let error = server_from("", &[("EXTENDDB__SERVER__CATALOG_UPGRADE", "always")]) + .expect_err("not a value"); + assert!(error.contains("always"), "{error}"); + assert_eq!(CatalogUpgrade::Refuse.as_str(), "refuse"); + assert_eq!(CatalogUpgrade::Apply.as_str(), "apply"); + } +} diff --git a/crates/config/src/display.rs b/crates/config/src/display.rs index f626b75a2..de5408c01 100644 --- a/crates/config/src/display.rs +++ b/crates/config/src/display.rs @@ -84,6 +84,14 @@ pub fn build_config_entries(cfg: &AppConfig) -> Vec<(String, String)> { .throttling_enabled .map_or("none".into(), |b| b.to_string()), ), + ( + "server.catalog_upgrade".into(), + cfg.server.catalog_upgrade.as_str().to_owned(), + ), + ( + "server.catalog_upgrade_lock_timeout".into(), + cfg.server.catalog_upgrade_lock_timeout.to_string(), + ), ( format!("storage.{backend}.connection_string"), r("connection_string", cfg.storage.connection_config()), diff --git a/crates/config/src/lib.rs b/crates/config/src/lib.rs index 5b1cb603a..2bc5aaff2 100644 --- a/crates/config/src/lib.rs +++ b/crates/config/src/lib.rs @@ -78,6 +78,17 @@ pub struct ServerConfig { /// Enable provisioned throughput throttling via token buckets. /// When `None` or `false`, all requests are allowed regardless of capacity. pub throttling_enabled: Option, + /// What `serve` does with a catalog that is behind this binary: refuse + /// it, or apply its pending migrations before it serves. `refuse` by + /// default, `apply` in a dev-mode build. `serve --migrate` sets `apply` + /// for one run. + #[serde(default = "catalog_upgrade::default_catalog_upgrade")] + pub catalog_upgrade: CatalogUpgrade, + /// Seconds `serve` waits under `catalog_upgrade = "apply"` for the + /// migration lock and for running servers before it exits 6 (default + /// 60, at most 86400). + #[serde(default = "catalog_upgrade::default_catalog_upgrade_lock_timeout")] + pub catalog_upgrade_lock_timeout: u64, } impl Default for ServerConfig { @@ -89,6 +100,8 @@ impl Default for ServerConfig { run_dir: default_run_dir(), tls: TlsConfig::default(), throttling_enabled: None, + catalog_upgrade: catalog_upgrade::default_catalog_upgrade(), + catalog_upgrade_lock_timeout: catalog_upgrade::default_catalog_upgrade_lock_timeout(), } } } @@ -505,6 +518,9 @@ pub fn pid_file_path_default(port: u16) -> PathBuf { } pub mod backup; +mod catalog_upgrade; +pub use catalog_upgrade::{CatalogUpgrade, MAX_CATALOG_UPGRADE_LOCK_TIMEOUT}; + mod display; pub use display::{MASK, build_config_entries, should_redact}; diff --git a/crates/server/src/serve.rs b/crates/server/src/serve.rs index 64ad37527..65c15660d 100644 --- a/crates/server/src/serve.rs +++ b/crates/server/src/serve.rs @@ -377,7 +377,8 @@ async fn serve_inner(params: ServeParams, port: u16) -> anyhow::Result<()> { installed(), &named, config_path.as_deref(), - ); + ) + .for_server(); return Err(CatalogRefusal { exit_code: error.exit_code(), message: advice::error_message(&error, &advice.advice()), diff --git a/crates/storage-cassandra/tests/migrations.rs b/crates/storage-cassandra/tests/migrations.rs index 3094558c2..62a4685fd 100644 --- a/crates/storage-cassandra/tests/migrations.rs +++ b/crates/storage-cassandra/tests/migrations.rs @@ -3,8 +3,9 @@ //! The catalog migrations against a live node: migration 1's definitions, //! the status of keyspaces that are not catalogs, the ledger, the migration -//! lock's lease, the serving registration and CreateAccount's account -//! migrations. Each test uses keyspaces of its own prefix and drops them. +//! lock's lease, the serving registration, CreateAccount's account +//! migrations and the startup policy `serve` runs before it opens the +//! catalog. Each test uses keyspaces of its own prefix and drops them. //! Skipped without a node unless `EXTENDDB_TEST_CASSANDRA=required`. //! //! With `EXTENDDB_BLESS_EXPECTED=1`, @@ -17,6 +18,8 @@ mod helpers; #[path = "migrations/lock.rs"] mod lock; mod migrations_support; +#[path = "migrations/startup.rs"] +mod startup; use std::sync::Arc; @@ -900,6 +903,7 @@ async fn a_create_account_stopped_before_its_row_leaves_a_current_catalog_a_retr backup: "back up the keyspaces", config: None, assignment: None, + serving: false, }; let message = status_message(&status, &advice); assert!( diff --git a/crates/storage-cassandra/tests/migrations/startup.rs b/crates/storage-cassandra/tests/migrations/startup.rs new file mode 100644 index 000000000..1e3be7c1d --- /dev/null +++ b/crates/storage-cassandra/tests/migrations/startup.rs @@ -0,0 +1,300 @@ +// Copyright 2026 ExtendDB contributors +// SPDX-License-Identifier: Apache-2.0 + +//! The startup policy `serve` runs before it opens the catalog +//! (`[server] catalog_upgrade`, or `serve --migrate`): under `apply` a +//! legacy catalog is migrated through the lock `migrate --yes` takes, a +//! current one is served with nothing written, one that needs a person +//! exits 5 with nothing written, a held lock makes the server wait and then +//! exit 6, and two `prepare_to_serve` runs that wait for the lock together, +//! whose connection strings name the two nodes of a two-node cluster when +//! the job has one, migrate once. + +use std::sync::Arc; +use std::sync::atomic::{AtomicUsize, Ordering}; +use std::time::{Duration, Instant}; + +use extenddb_storage::management_store::{ManagementStore, SettingsStore}; +use extenddb_storage::migrations::{ + CatalogMigrations, CatalogStatus, LedgerRow, MigrationError, MigrationId, Prepared, Startup, + StoreKind, Target, exit, prepare_to_serve, +}; +use extenddb_storage_cassandra::CassandraCatalogStore; +use extenddb_storage_cassandra::cassandra_util::CassandraSession; +use extenddb_storage_cassandra::migrations::{ + CassandraCatalogMigrations, LeaseTimes, MigrationLock, catalog_status, run_baseline_unrecorded, +}; + +use super::{deployment, target_of}; +use crate::helpers; +use crate::migrations_support::{TIMEOUT, cql, keyspace, new_prefix, pinned_session, session}; + +const ACCOUNT: &str = "111111111111"; + +fn startup(apply: bool, lock_timeout: Duration) -> Startup<'static> { + Startup { + apply, + creates_uninitialized: false, + release: "1.0.0-test", + lock_timeout, + heartbeat: Startup::HEARTBEAT, + } +} + +/// The policy as `serve` runs it, on the connection string the config +/// file gives. +async fn prepare(target: &Target, startup: &Startup<'_>) -> Result { + prepare_to_serve(&CassandraCatalogMigrations, target, startup, &|_| {}).await +} + +/// The node `EXTENDDB_TEST_CASSANDRA_SECOND_CONTACT_POINT` names, the second +/// node of a two-node cluster; the test node when it is not set. +fn second_contact_point() -> String { + std::env::var("EXTENDDB_TEST_CASSANDRA_SECOND_CONTACT_POINT") + .unwrap_or_else(|_| helpers::test_contact_point()) +} + +/// [`target_of`] with [`second_contact_point`] as its contact point. +fn second_target_of(prefix: &str) -> Target { + let config = helpers::test_config(); + Target::at(format!( + "{}:{}@{}/{prefix}", + config.username.unwrap_or_default(), + config.password.unwrap_or_default(), + second_contact_point(), + )) +} + +/// A catalog as a release before 1.0 left it: migration 1's tables with no +/// ledger rows, and `catalog_version` 0.0.4. +async fn legacy_catalog(session: &Arc, prefix: &str) { + let catalog = format!("{prefix}_catalog"); + keyspace(session, &catalog).await; + run_baseline_unrecorded(session, &catalog, StoreKind::Catalog) + .await + .expect("the legacy tables"); + cql( + session, + &format!("INSERT INTO {catalog}.settings (key, value) VALUES ('catalog_version', '0.0.4')"), + ) + .await; +} + +/// What a run could change in the catalog: its ledger rows with the time +/// each was applied, its `catalog_version` row, and the lock row. +async fn state( + session: &Arc, + prefix: &str, +) -> (Vec, Option, Option) { + let rows = CassandraCatalogMigrations + .catalog_ledger(&target_of(prefix)) + .await + .expect("the ledger"); + let store = CassandraCatalogStore::catalog_only(session.clone(), prefix.to_owned()); + let version = store.get_setting("catalog_version").await.expect("read"); + let lock = store.get_setting("migration_lock").await.expect("read"); + (rows, version, lock) +} + +#[tokio::test] +async fn apply_migrates_a_legacy_catalog_and_refuse_writes_nothing() { + if helpers::skip_without_cassandra() { + return; + } + let session = session().await; + let (prefix, _drops) = new_prefix("start_apply"); + legacy_catalog(&session, &prefix).await; + let target = target_of(&prefix); + let before = state(&session, &prefix).await; + let err = prepare(&target, &startup(false, TIMEOUT)) + .await + .expect_err("refused"); + assert_eq!(err.exit_code(), exit::PENDING, "{err:?}"); + assert_eq!(state(&session, &prefix).await, before, "refuse wrote"); + + let prepared = prepare(&target, &startup(true, TIMEOUT)) + .await + .expect("applied"); + let report = prepared.run.expect("a run"); + assert_eq!(report.applied.len(), MigrationId::ALL.len(), "{report:?}"); + assert_eq!( + catalog_status(session.clone(), &prefix) + .await + .expect("status"), + CatalogStatus::Current { + version: MigrationId::LATEST.number() + } + ); +} + +#[tokio::test] +async fn apply_on_a_current_catalog_writes_nothing() { + if helpers::skip_without_cassandra() { + return; + } + let session = session().await; + let (prefix, _drops) = new_prefix("start_current"); + deployment(&session, &prefix).await; + let before = state(&session, &prefix).await; + let prepared = prepare(&target_of(&prefix), &startup(true, TIMEOUT)) + .await + .expect("served"); + assert_eq!(prepared, Prepared::default()); + assert_eq!( + state(&session, &prefix).await, + before, + "a current catalog was written to" + ); +} + +#[tokio::test] +async fn apply_on_a_catalog_that_needs_attention_exits_5_and_writes_nothing() { + if helpers::skip_without_cassandra() { + return; + } + let session = session().await; + let (prefix, _drops) = new_prefix("start_attention"); + legacy_catalog(&session, &prefix).await; + cql( + &session, + &format!( + "INSERT INTO {prefix}_catalog.accounts (account_id, account_name, created_at) VALUES \ + ('{ACCOUNT}', 'one', toTimestamp(now()))" + ), + ) + .await; + // A policy migration 2 cannot rewrite: both forms of one tag key, with + // different values. + let colliding: serde_json::Value = serde_json::from_str( + r#"{"Version":"2012-10-17","Statement":[{"Effect":"Deny","Action":"dynamodb:*","Resource":"*","Condition":{"StringEquals":{"aws:ResourceTag/env":"prod","dynamodb:ResourceTag/env":"dev"}}}]}"#, + ) + .expect("json"); + let store = CassandraCatalogStore::catalog_only(session.clone(), prefix.clone()); + store.create_user(ACCOUNT, "dev", None).await.expect("user"); + store + .put_policy(ACCOUNT, "user", "dev", "colliding", &colliding) + .await + .expect("policy"); + let target = target_of(&prefix); + let before = state(&session, &prefix).await; + let err = prepare(&target, &startup(true, TIMEOUT)) + .await + .expect_err("refused"); + assert!( + matches!( + err, + MigrationError::Status(CatalogStatus::NeedsAttention { .. }) + ), + "{err:?}" + ); + assert_eq!(err.exit_code(), exit::ATTENTION); + assert_eq!( + state(&session, &prefix).await, + before, + "a refused run wrote" + ); +} + +/// Another process holds the migration lock: the server waits for it up +/// to the timeout, then exits 6 with the catalog unchanged. +#[tokio::test] +async fn apply_waits_for_a_held_migration_lock_and_exits_6() { + if helpers::skip_without_cassandra() { + return; + } + let session = session().await; + let (prefix, _drops) = new_prefix("start_locked"); + legacy_catalog(&session, &prefix).await; + let holder = MigrationLock::acquire( + session.clone(), + &format!("{prefix}_catalog"), + LeaseTimes::DEFAULT, + TIMEOUT, + ) + .await + .expect("another process's lock"); + let before = state(&session, &prefix).await; + let started = Instant::now(); + let err = prepare(&target_of(&prefix), &startup(true, Duration::from_secs(3))) + .await + .expect_err("locked"); + assert!( + started.elapsed() >= Duration::from_millis(2800), + "it waited {:?}", + started.elapsed() + ); + assert!(matches!(err, MigrationError::Locked(_)), "{err:?}"); + assert_eq!(err.exit_code(), exit::LOCKED); + assert_eq!( + state(&session, &prefix).await, + before, + "a server that waited wrote" + ); + holder.release().await; +} + +/// Two `prepare_to_serve` runs under `apply` on a legacy catalog, their +/// connection strings naming different nodes when the job has two, both +/// waiting for the lock another process holds, as the checks of two servers +/// started together do after their first status read: once it is free, one +/// migrates the catalog, and the other takes the lock after it and applies +/// nothing. Each run's session reaches the cluster at the node its +/// connection string names and then sends requests to both nodes in turn, +/// as a server's session does. The servers are not started here; one of two +/// servers started together can exit 6 when it registers while the other +/// holds the lock. +#[tokio::test] +async fn two_prepare_to_serve_runs_under_apply_migrate_a_legacy_catalog_once() { + if helpers::skip_without_cassandra() { + return; + } + let session = session().await; + let (prefix, _drops) = new_prefix("start_two"); + legacy_catalog(&session, &prefix).await; + let holder = MigrationLock::acquire( + session.clone(), + &format!("{prefix}_catalog"), + LeaseTimes::DEFAULT, + TIMEOUT, + ) + .await + .expect("another process's lock"); + let waiting = AtomicUsize::new(0); + let progress = |line: &str| { + if line.starts_with("taking the migration lock") { + waiting.fetch_add(1, Ordering::SeqCst); + } + }; + // Each run waits for the holder, and the second also for the first + // one's migration. + let apply = startup(true, TIMEOUT * 2); + let (first, second) = (target_of(&prefix), second_target_of(&prefix)); + let free = async { + while waiting.load(Ordering::SeqCst) < 2 { + tokio::time::sleep(Duration::from_millis(20)).await; + } + holder.release().await; + }; + let (a, b, ()) = tokio::join!( + prepare_to_serve(&CassandraCatalogMigrations, &first, &apply, &progress), + prepare_to_serve(&CassandraCatalogMigrations, &second, &apply, &progress), + free, + ); + let mut applied: Vec = [a.expect("first"), b.expect("second")] + .iter() + .map(|p| p.run.as_ref().expect("each took the lock").applied.len()) + .collect(); + applied.sort_unstable(); + assert!( + applied[0] == 0 && applied[1] > 0, + "one migrates, and the other takes the lock after it and applies nothing: {applied:?}" + ); + assert_eq!( + catalog_status(pinned_session(&second_contact_point()).await, &prefix) + .await + .expect("status"), + CatalogStatus::Current { + version: MigrationId::LATEST.number() + } + ); +} diff --git a/crates/storage-mongodb/src/lib.rs b/crates/storage-mongodb/src/lib.rs index 3580b5fb5..6cdb3ea77 100644 --- a/crates/storage-mongodb/src/lib.rs +++ b/crates/storage-mongodb/src/lib.rs @@ -305,10 +305,14 @@ pub fn backend() -> extenddb_storage::Backend { }) }, server_components: server_components_factory, - catalog_migrations: &migrations::MongoCatalogMigrations, + catalog_migrations: &CATALOG_MIGRATIONS, } } +/// The catalog migrations of every deployment this backend serves. +static CATALOG_MIGRATIONS: migrations::MongoCatalogMigrations = + migrations::MongoCatalogMigrations::new(); + // ============================================================================ // MongoEngine // ============================================================================ diff --git a/crates/storage-mongodb/src/migrations/commands.rs b/crates/storage-mongodb/src/migrations/commands.rs index 8344b8cb7..eead1330e 100644 --- a/crates/storage-mongodb/src/migrations/commands.rs +++ b/crates/storage-mongodb/src/migrations/commands.rs @@ -24,12 +24,46 @@ use extenddb_storage::migrations::{ use super::foreign::foreign_unless_a_catalog; use super::{ - CATALOG_DATABASE, DATA_DATABASE, Lease, MigrationLock, MongoMigrations, MongoTarget, Timing, - catalog_status, status_holding, + Lease, MigrationLock, MongoMigrations, MongoTarget, Timing, catalog_status, status_holding, }; -/// The MongoDB backend's catalog migrations for the commands. -pub struct MongoCatalogMigrations; +/// The MongoDB backend's catalog migrations for the commands, on the +/// databases `extenddb_catalog` and `extenddb_data` of the deployment a +/// [`Target`] names. +#[derive(Debug, Default)] +pub struct MongoCatalogMigrations { + /// The catalog and data databases' names instead of those two, for + /// tests that share one server. + databases: Option<(String, String)>, +} + +impl MongoCatalogMigrations { + /// The catalog migrations of a deployment's two databases. + #[must_use] + pub const fn new() -> Self { + Self { databases: None } + } + + /// The catalog migrations of a deployment in databases of other names, + /// for tests that share one server. + #[cfg(any(test, feature = "test-util"))] + #[must_use] + pub fn with_databases(catalog: impl Into, data: impl Into) -> Self { + Self { + databases: Some((catalog.into(), data.into())), + } + } + + /// The deployment at `location`, in this value's databases. + fn target(&self, location: &str) -> MongoTarget { + let mut target = MongoTarget::new(location); + if let Some((catalog, data)) = &self.databases { + target.catalog.clone_from(catalog); + target.data.clone_from(data); + } + target + } +} /// What the migration lock carries for [`CatalogMigrations::run`] and /// [`CatalogMigrations::forget`]. @@ -56,15 +90,16 @@ impl CatalogMigrations for MongoCatalogMigrations { Listed::of(&super::migration(id)) } - fn backup_advice(&self, _target: &Target) -> String { + fn backup_advice(&self, target: &Target) -> String { + let MongoTarget { catalog, data, .. } = self.target(&target.location); format!( - "back up both MongoDB databases, the catalog database {CATALOG_DATABASE} and the data \ - database {DATA_DATABASE}" + "back up both MongoDB databases, the catalog database {catalog} and the data \ + database {data}" ) } async fn status(&self, target: &Target) -> Result { - catalog_status(&MongoTarget::new(&target.location)).await + catalog_status(&self.target(&target.location)).await } /// Read as the holder, so the requests of a long status read are @@ -79,7 +114,7 @@ impl CatalogMigrations for MongoCatalogMigrations { } async fn catalog_ledger(&self, target: &Target) -> Result, MigrationError> { - let migrations = MongoMigrations::open(&MongoTarget::new(&target.location), None).await?; + let migrations = MongoMigrations::open(&self.target(&target.location), None).await?; let rows = Runner::new(&migrations, "").catalog_ledger().await; migrations.close().await; rows @@ -87,7 +122,7 @@ impl CatalogMigrations for MongoCatalogMigrations { async fn lock(&self, target: &Target, timeout: Duration) -> Result { lock( - &MongoTarget::new(&target.location), + &self.target(&target.location), target.data_connection.is_some(), timeout, Timing::PRODUCTION, @@ -122,6 +157,15 @@ impl CatalogMigrations for MongoCatalogMigrations { migrations.close().await; result } + + /// Delete the lock document with the lock's own client, on this + /// runtime, so the next migration or server need not wait for its + /// lease. Dropping the lock afterwards does nothing. + async fn release(&self, lock: HeldLock) { + if let Ok(held) = held(&lock) { + held.lock.release_held().await; + } + } } /// Take the migration lock on `target`, waiting up to `timeout` for another @@ -186,11 +230,17 @@ mod tests { #[test] fn the_backup_advice_names_both_databases_and_no_password() { let target = Target::at("mongodb://app:s3cret@localhost:27017/?replicaSet=rs0"); - let advice = MongoCatalogMigrations.backup_advice(&target); + let advice = MongoCatalogMigrations::new().backup_advice(&target); assert_eq!( advice, "back up both MongoDB databases, the catalog database extenddb_catalog and the data \ database extenddb_data" ); + let advice = + MongoCatalogMigrations::with_databases("t_catalog", "t_data").backup_advice(&target); + assert!( + advice.contains("t_catalog and the data database t_data"), + "{advice}" + ); } } diff --git a/crates/storage-mongodb/src/migrations/locks.rs b/crates/storage-mongodb/src/migrations/locks.rs index 7d92c8f6e..3bf568689 100644 --- a/crates/storage-mongodb/src/migrations/locks.rs +++ b/crates/storage-mongodb/src/migrations/locks.rs @@ -31,6 +31,7 @@ //! own first and then looks for the other, so two that start together //! cannot both miss each other. +use std::sync::atomic::{AtomicBool, Ordering}; use std::sync::{Arc, Mutex}; use std::time::{Duration, Instant}; @@ -250,7 +251,8 @@ pub struct MigrationLock { token: String, lease: Arc, renewal: JoinHandle<()>, - released: bool, + /// Set by the first release, so a later one and `Drop` do nothing. + released: AtomicBool, } impl MigrationLock { @@ -285,7 +287,7 @@ impl MigrationLock { token, lease, renewal, - released: false, + released: AtomicBool::new(false), }); } if started.elapsed() >= timeout { @@ -344,9 +346,19 @@ impl MigrationLock { } /// Delete the lock document if this process still owns it. - pub async fn release(mut self) { + pub async fn release(self) { + self.release_held().await; + } + + /// [`MigrationLock::release`] for a caller that holds the lock behind a + /// shared reference, as the commands' `HeldLock` does: the delete goes + /// through this lock's own client, on the caller's runtime. Only the + /// first call deletes, and `Drop` then does nothing. + pub(crate) async fn release_held(&self) { self.renewal.abort(); - self.released = true; + if self.released.swap(true, Ordering::SeqCst) { + return; + } let _ = tokio::time::timeout( REQUEST_TIMEOUT, self.settings @@ -358,9 +370,9 @@ impl MigrationLock { /// Stop renewing and keep the document, as a process that was killed /// does: the lock then ends when its lease does. #[cfg(feature = "test-util")] - pub fn abandon(mut self) { + pub fn abandon(self) { self.renewal.abort(); - self.released = true; + self.released.store(true, Ordering::SeqCst); } } @@ -371,7 +383,7 @@ impl Drop for MigrationLock { /// on a thread of its own with a client of its own. fn drop(&mut self) { self.renewal.abort(); - if self.released { + if *self.released.get_mut() { return; } let target = self.target.clone(); diff --git a/crates/storage-mongodb/tests/migrations_startup.rs b/crates/storage-mongodb/tests/migrations_startup.rs new file mode 100644 index 000000000..209c86900 --- /dev/null +++ b/crates/storage-mongodb/tests/migrations_startup.rs @@ -0,0 +1,271 @@ +// SPDX-License-Identifier: Apache-2.0 + +//! The startup policy `serve` runs before it opens the catalog +//! (`[server] catalog_upgrade`, or `serve --migrate`), on released +//! catalogs: under `apply` a catalog behind the binary is migrated through +//! the lock `migrate --yes` takes, a current one is served with nothing +//! written, one that needs a person exits 5 with nothing written, a held +//! migration lock makes the server wait and then exit 6, and two +//! `prepare_to_serve` runs that wait for the lock together migrate once. + +mod migrations_support; + +use std::sync::atomic::{AtomicUsize, Ordering}; +use std::time::{Duration, Instant}; + +use bson::{Document, doc}; +use extenddb_storage::migrations::{ + CatalogStatus, MigrationError, MigrationId, Prepared, Startup, Target, exit, prepare_to_serve, +}; +use extenddb_storage_mongodb::migrations::MongoCatalogMigrations; +use migrations_support::{Deployment, fixture, server}; + +fn startup(apply: bool, lock_timeout: Duration) -> Startup<'static> { + Startup { + apply, + creates_uninitialized: false, + release: "1.0.0-test", + lock_timeout, + heartbeat: Startup::HEARTBEAT, + } +} + +/// The policy as `serve` runs it, through the backend's catalog migrations +/// on the deployment's databases. +async fn prepare(d: &Deployment, startup: &Startup<'_>) -> Result { + let migrations = MongoCatalogMigrations::with_databases(&d.target.catalog, &d.target.data); + let target = Target::at(&d.target.connection_string); + prepare_to_serve(&migrations, &target, startup, &|_| {}).await +} + +/// What a run could change: every document of every collection of both +/// databases. +async fn state(d: &Deployment) -> Vec<(String, Vec)> { + let mut found = Vec::new(); + for db in [d.catalog(), d.data()] { + for name in Deployment::collections(&db).await { + let documents = Deployment::documents(&db, &name).await; + found.push((format!("{}.{name}", db.name()), documents)); + } + } + found +} + +#[tokio::test(flavor = "multi_thread")] +async fn apply_migrates_a_released_catalog_and_refuse_writes_nothing() { + let Some(uri) = server() else { return }; + let d = Deployment::new(&uri, "start_apply").await; + fixture::load(&d, &fixture::read("0.1.14")).await; + let before = state(&d).await; + let err = prepare(&d, &startup(false, Duration::from_secs(10))) + .await + .expect_err("refused"); + assert_eq!(err.exit_code(), exit::PENDING, "{err:?}"); + assert!(state(&d).await == before, "refuse wrote to the catalog"); + + let prepared = prepare(&d, &startup(true, Duration::from_secs(10))) + .await + .expect("applied"); + let report = prepared.run.expect("a run"); + assert_eq!(report.applied.len(), 7, "{report:?}"); + assert_eq!( + d.status().await, + CatalogStatus::Current { + version: MigrationId::LATEST.number() + } + ); + d.drop_databases().await; +} + +#[tokio::test(flavor = "multi_thread")] +async fn apply_on_a_current_catalog_writes_nothing() { + let Some(uri) = server() else { return }; + let d = Deployment::new(&uri, "start_current").await; + fixture::load(&d, &fixture::read("0.1.14")).await; + d.migrate().await.expect("migrate"); + let before = state(&d).await; + let prepared = prepare(&d, &startup(true, Duration::from_secs(10))) + .await + .expect("served"); + assert_eq!(prepared, Prepared::default()); + assert!( + state(&d).await == before, + "a current catalog was written to" + ); + d.drop_databases().await; +} + +#[tokio::test(flavor = "multi_thread")] +async fn apply_on_a_catalog_that_needs_attention_exits_5_and_writes_nothing() { + let Some(uri) = server() else { return }; + let d = Deployment::new(&uri, "start_attention").await; + fixture::load(&d, &fixture::read("0.1.14")).await; + // An IAM user whose policy migration 2 cannot rewrite: both forms of + // one tag key, with different values. + let catalog = d.catalog(); + let account = catalog + .collection::("accounts") + .find_one(doc! {}) + .await + .expect("read accounts") + .expect("an account"); + let account = account + .get_str("account_id") + .or_else(|_| account.get_str("_id")) + .expect("an account id") + .to_owned(); + let now = bson::DateTime::now(); + catalog + .collection::("iam_users") + .insert_one(doc! { + "account_id": &account, + "user_name": "collider", + "user_arn": format!("arn:aws:iam::{account}:user/collider"), + "created_at": now, + }) + .await + .expect("a user"); + catalog + .collection::("iam_policies") + .insert_one(doc! { + "account_id": &account, + "principal_type": "user", + "principal_name": "collider", + "policy_name": "p", + "policy_document": { + "Version": "2012-10-17", + "Statement": [{ + "Effect": "Deny", + "Action": "dynamodb:*", + "Resource": "*", + "Condition": { "StringEquals": { + "aws:ResourceTag/env": "prod", + "dynamodb:ResourceTag/env": "dev", + } }, + }], + }, + "created_at": now, + }) + .await + .expect("a colliding policy"); + assert!( + matches!(d.status().await, CatalogStatus::NeedsAttention { .. }), + "the policy does not collide" + ); + let before = state(&d).await; + let err = prepare(&d, &startup(true, Duration::from_secs(10))) + .await + .expect_err("refused"); + assert!( + matches!( + err, + MigrationError::Status(CatalogStatus::NeedsAttention { .. }) + ), + "{err:?}" + ); + assert_eq!(err.exit_code(), exit::ATTENTION); + assert!( + state(&d).await == before, + "a refused run wrote to the catalog" + ); + d.drop_databases().await; +} + +/// Another migration's lock, as its claim writes it: the server waits for +/// it up to the timeout, then exits 6 with the catalog unchanged. +#[tokio::test(flavor = "multi_thread")] +async fn apply_waits_for_a_held_migration_lock_and_exits_6() { + let Some(uri) = server() else { return }; + let d = Deployment::new(&uri, "start_locked").await; + fixture::load(&d, &fixture::read("0.1.14")).await; + another_migrations_lock(&d).await; + let before = state(&d).await; + let started = Instant::now(); + let err = prepare(&d, &startup(true, Duration::from_secs(2))) + .await + .expect_err("locked"); + assert!( + started.elapsed() >= Duration::from_millis(1800), + "it waited {:?}", + started.elapsed() + ); + assert!(matches!(err, MigrationError::Locked(_)), "{err:?}"); + assert_eq!(err.exit_code(), exit::LOCKED); + assert!( + state(&d).await == before, + "a server that waited wrote to the catalog" + ); + d.drop_databases().await; +} + +/// Another migration's lock document, as its claim writes it, for two +/// minutes. +async fn another_migrations_lock(d: &Deployment) { + d.catalog() + .collection::("settings") + .insert_one(doc! { + "_id": "migration_lock", + "owner": "another", + "expires_at": bson::DateTime::from_millis( + bson::DateTime::now().timestamp_millis() + 120_000 + ), + }) + .await + .expect("another migration's lock"); +} + +/// Two `prepare_to_serve` runs under `apply` on a released catalog, both +/// waiting for the lock another migration holds, as the checks of two +/// servers started together do after their first status read: once it is +/// free, one migrates the catalog, and the other takes the lock after it +/// and applies nothing. The servers are not started here; one of two +/// servers started together can exit 6 when it registers while the other +/// holds the lock. +#[tokio::test(flavor = "multi_thread")] +async fn two_prepare_to_serve_runs_under_apply_migrate_once() { + let Some(uri) = server() else { return }; + let d = Deployment::new(&uri, "start_two").await; + fixture::load(&d, &fixture::read("0.1.12")).await; + another_migrations_lock(&d).await; + let migrations = MongoCatalogMigrations::with_databases(&d.target.catalog, &d.target.data); + let target = Target::at(&d.target.connection_string); + let waiting = AtomicUsize::new(0); + let progress = |line: &str| { + if line.starts_with("taking the migration lock") { + waiting.fetch_add(1, Ordering::SeqCst); + } + }; + let apply = startup(true, Duration::from_secs(60)); + let free = async { + while waiting.load(Ordering::SeqCst) < 2 { + tokio::time::sleep(Duration::from_millis(20)).await; + } + d.catalog() + .collection::("settings") + .delete_one(doc! { "_id": "migration_lock", "owner": "another" }) + .await + .expect("the other migration releases its lock"); + }; + let (a, b, ()) = tokio::join!( + prepare_to_serve(&migrations, &target, &apply, &progress), + prepare_to_serve(&migrations, &target, &apply, &progress), + free, + ); + let mut applied: Vec = [a.expect("first"), b.expect("second")] + .iter() + .map(|p| p.run.as_ref().expect("each took the lock").applied.len()) + .collect(); + applied.sort_unstable(); + assert_eq!( + applied, + [0, 7], + "one migrates, and the other takes the lock after it and applies nothing" + ); + assert_eq!( + d.status().await, + CatalogStatus::Current { + version: MigrationId::LATEST.number() + } + ); + d.drop_databases().await; +} diff --git a/crates/storage-postgres/src/migrations/sessions.rs b/crates/storage-postgres/src/migrations/sessions.rs index aa6fb12b3..3a591db5e 100644 --- a/crates/storage-postgres/src/migrations/sessions.rs +++ b/crates/storage-postgres/src/migrations/sessions.rs @@ -428,7 +428,8 @@ fn give_to( /// they run and each with the role that runs it ([`give_to`]). Every /// migration that alters such an object fails with SQLSTATE 42501, and so /// does one that creates a table where the role may not, so the note -/// refuses `migrate --yes` before it takes the lock. +/// refuses `migrate --yes`, and a server under `catalog_upgrade = "apply"`, +/// before they take the lock. /// /// # Errors /// @@ -501,9 +502,10 @@ pub(crate) async fn ownership_note( .join(" "); Ok(Some(StatusNote { text: format!( - "{}. Migrations run as {role}, so migrate --yes refuses to apply any while this \ - holds. Connected to {name}, run these statements in this order, each as the role \ - named before it: {steps}", + "{}. Migrations run as {role}, so migrate --yes, and serve with --migrate or \ + catalog_upgrade = \"apply\", refuse to apply any while this holds. Connected to \ + {name}, run these statements in this order, each as the role named before it: \ + {steps}", found.join("; "), ), refuses_runs: true, diff --git a/crates/storage-postgres/src/migrations/vector_extension.rs b/crates/storage-postgres/src/migrations/vector_extension.rs index d8e40a3d0..6bcd6c383 100644 --- a/crates/storage-postgres/src/migrations/vector_extension.rs +++ b/crates/storage-postgres/src/migrations/vector_extension.rs @@ -95,8 +95,8 @@ pub async fn try_create_vector_extension( failures.push(format!("as the application role: {e}")); format!( "NOTICE: could not create the pgvector extension ({}). Vector indexes are \ - unavailable until it is installed; pass --pg-user with a role that may create \ - it to retry.", + unavailable until it is installed; to retry, run extenddb migrate --yes \ + --pg-user with a role that may create it.", failures.join("; ") ) } diff --git a/crates/storage-postgres/tests/migrations_guards.rs b/crates/storage-postgres/tests/migrations_guards.rs index e13886aed..972bc44fb 100644 --- a/crates/storage-postgres/tests/migrations_guards.rs +++ b/crates/storage-postgres/tests/migrations_guards.rs @@ -16,7 +16,8 @@ use std::time::{Duration, Instant}; use async_trait::async_trait; use extenddb_storage::migrations::{ CodeBody, Done, HasManagementStore, Kind, LedgerRow, MigrationBackend, MigrationError, - MigrationId, Outcome, RunKind, Runner, Step, StoreKind, StoreRef, Target, before_lock, exit, + MigrationId, Outcome, RunKind, Runner, Startup, Step, StoreKind, StoreRef, Target, before_lock, + exit, prepare_to_serve, }; use extenddb_storage_postgres::migrations::{ MigrationLock, PostgresCatalogMigrations, PostgresMigrations, PostgresStores, PostgresTarget, @@ -500,6 +501,7 @@ async fn a_role_that_does_not_own_the_tables_is_told_what_to_run() { &PostgresCatalogMigrations, &Target::at(location.as_str()), RunKind::Migrate, + "migrate --yes", ) .await .expect_err("migrate --yes refuses before the lock"); @@ -508,6 +510,33 @@ async fn a_role_that_does_not_own_the_tables_is_told_what_to_run() { refused.to_string().contains("no lock was taken"), "{refused}" ); + // A server under `catalog_upgrade = "apply"` checks the same notes + // before it takes the lock, and refuses with them and the same code, + // naming itself. + let startup = Startup { + apply: true, + creates_uninitialized: false, + release: "1.0.0-test", + lock_timeout: Duration::from_secs(5), + heartbeat: Startup::HEARTBEAT, + }; + let refused = prepare_to_serve( + &PostgresCatalogMigrations, + &Target::at(location.as_str()), + &startup, + &|_| {}, + ) + .await + .expect_err("a server under apply refuses before the lock"); + assert_eq!(refused.exit_code(), exit::ERROR); + let shown = refused.to_string(); + assert!( + shown.starts_with( + "serve with --migrate or catalog_upgrade = \"apply\" refuses to apply migrations" + ) && shown.contains(&format!("the application role {role} does not own")) + && shown.contains("no lock was taken"), + "{shown}" + ); let err = migrate(&target, "test", Duration::from_secs(5)) .await .expect_err("the role cannot alter tables it does not own"); diff --git a/crates/storage-postgres/tests/migrations_startup.rs b/crates/storage-postgres/tests/migrations_startup.rs new file mode 100644 index 000000000..7d8db99f8 --- /dev/null +++ b/crates/storage-postgres/tests/migrations_startup.rs @@ -0,0 +1,356 @@ +// SPDX-License-Identifier: Apache-2.0 +//! The startup policy `serve` runs before it opens the catalog +//! (`[server] catalog_upgrade`, or `serve --migrate`), on released +//! catalogs: under `apply` a catalog behind the binary is migrated through +//! the lock `migrate --yes` takes, a current one is served with nothing +//! written, one that needs a person exits 5 with nothing written, a held +//! migration lock makes the server wait and then exit 6, a zero lock +//! timeout tries each key once, the waits of a run share one timeout, and +//! two `prepare_to_serve` runs that wait for the lock together migrate +//! once. See `migrations_support` for the database these tests need. + +mod migrations_support; + +use std::sync::atomic::{AtomicUsize, Ordering}; +use std::time::{Duration, Instant}; + +use extenddb_storage::migrations::{ + CatalogStatus, MigrationError, Prepared, RunKind, Startup, Target, WhenCurrent, exit, + prepare_to_serve, run_with_lock, +}; +use extenddb_storage_postgres::migrations::{Definitions, PostgresCatalogMigrations}; +use migrations_support::{ + LATEST, Scratch, base_conn, describe_pool, ledger, settings, skip, step_count, +}; + +/// The advisory keys of the migration lock and the serving registration, +/// `NAMESPACE`, `MIGRATION_KEY` and `SERVING_KEY` in +/// `src/migrations/locks.rs`. +const NAMESPACE: i32 = 0x0045_4442; +const MIGRATION_KEY: i32 = 1; +const SERVING_KEY: i32 = 2; + +fn startup(apply: bool, lock_timeout: Duration) -> Startup<'static> { + Startup { + apply, + creates_uninitialized: false, + release: "1.0.0-test", + lock_timeout, + heartbeat: Startup::HEARTBEAT, + } +} + +/// The policy as `serve` runs it, on the catalog database's URL, which is +/// all the config file gives. +async fn prepare(s: &Scratch, startup: &Startup<'_>) -> Result { + let target = Target::at(s.catalog_url()); + prepare_to_serve(&PostgresCatalogMigrations, &target, startup, &|_| {}).await +} + +/// What a run could change: both databases' definitions, the catalog's +/// settings, and each ledger row with the time it was applied. +async fn state(s: &Scratch) -> (Definitions, Definitions, Vec<(String, String)>, Vec) { + let (catalog, data) = (s.catalog().await, s.data().await); + let mut rows = Vec::new(); + for p in [&catalog, &data] { + let applied: Vec<(i32, String)> = + sqlx::query_as("SELECT id, applied_at::text FROM extenddb_migrations ORDER BY id") + .fetch_all(p) + .await + .unwrap_or_default(); + rows.extend(applied.into_iter().map(|(id, at)| format!("{id} {at}"))); + } + let found = ( + describe_pool(&catalog).await, + describe_pool(&data).await, + settings(&catalog).await.into_iter().collect(), + rows, + ); + catalog.close().await; + data.close().await; + found +} + +#[tokio::test] +async fn apply_migrates_a_released_catalog_and_refuse_writes_nothing() { + let Some(base) = base_conn() else { + return skip("startup apply"); + }; + let s = Scratch::new(&base, "pgs_apply").await; + s.load("0.1.14").await; + let before = state(&s).await; + let err = prepare(&s, &startup(false, Duration::from_secs(10))) + .await + .expect_err("refused"); + assert_eq!(err.exit_code(), exit::PENDING, "{err:?}"); + assert!(state(&s).await == before, "refuse wrote to the catalog"); + + let prepared = prepare(&s, &startup(true, Duration::from_secs(10))) + .await + .expect("applied"); + let report = prepared.run.expect("a run"); + assert_eq!(report.applied.len(), step_count()); + assert_eq!(report.to, Some(LATEST)); + assert_eq!(s.status().await, CatalogStatus::Current { version: LATEST }); +} + +#[tokio::test] +async fn apply_on_a_current_catalog_writes_nothing() { + let Some(base) = base_conn() else { + return skip("startup current"); + }; + let s = Scratch::new(&base, "pgs_current").await; + s.load("0.1.14").await; + s.migrate_through(extenddb_storage::migrations::MigrationId::LATEST) + .await; + let before = state(&s).await; + let prepared = prepare(&s, &startup(true, Duration::from_secs(10))) + .await + .expect("served"); + assert_eq!(prepared, Prepared::default()); + assert!( + state(&s).await == before, + "a current catalog was written to" + ); +} + +#[tokio::test] +async fn apply_on_a_catalog_that_needs_attention_exits_5_and_writes_nothing() { + let Some(base) = base_conn() else { + return skip("startup attention"); + }; + let s = Scratch::new(&base, "pgs_attention").await; + s.load("0.1.14").await; + let catalog = s.catalog().await; + let both = r#"{"Version":"2012-10-17","Statement":[{"Effect":"Deny","Action":"dynamodb:*","Resource":"*","Condition":{"StringEquals":{"dynamodb:ResourceTag/env":"prod","aws:ResourceTag/env":"dev"}}}]}"#; + sqlx::query( + "UPDATE iam_policies SET policy_document = $1::jsonb WHERE principal_name = 'tester'", + ) + .bind(both) + .execute(&catalog) + .await + .unwrap(); + catalog.close().await; + let before = state(&s).await; + let err = prepare(&s, &startup(true, Duration::from_secs(10))) + .await + .expect_err("refused"); + assert!( + matches!( + err, + MigrationError::Status(CatalogStatus::NeedsAttention { .. }) + ), + "{err:?}" + ); + assert_eq!(err.exit_code(), exit::ATTENTION); + assert!( + state(&s).await == before, + "a refused run wrote to the catalog" + ); +} + +/// Another session holds the migration lock's key, as a running migration +/// does: the server waits for it up to the timeout, then exits 6 with the +/// catalog unchanged. +#[tokio::test] +async fn apply_waits_for_a_held_migration_lock_and_exits_6() { + let Some(base) = base_conn() else { + return skip("startup locked"); + }; + let s = Scratch::new(&base, "pgs_locked").await; + s.load("0.1.14").await; + let before = state(&s).await; + let holder = s.catalog().await; + let mut tx = holder.begin().await.unwrap(); + sqlx::query("SELECT pg_advisory_xact_lock($1, $2)") + .bind(NAMESPACE) + .bind(MIGRATION_KEY) + .execute(&mut *tx) + .await + .unwrap(); + let started = Instant::now(); + let err = prepare(&s, &startup(true, Duration::from_secs(2))) + .await + .expect_err("locked"); + assert!( + started.elapsed() >= Duration::from_millis(1800), + "it waited {:?}", + started.elapsed() + ); + assert!(matches!(err, MigrationError::Locked(_)), "{err:?}"); + assert_eq!(err.exit_code(), exit::LOCKED); + tx.rollback().await.unwrap(); + holder.close().await; + assert!( + state(&s).await == before, + "a server that waited wrote to the catalog" + ); +} + +/// Two `prepare_to_serve` runs under `apply` on a released catalog, both +/// waiting for the migration lock another session holds, as the checks of +/// two servers started together do after their first status read: once it +/// is free, one migrates the catalog, and the other takes the lock after it +/// and applies nothing. The servers are not started here; one of two +/// servers started together can exit 6 when it registers while the other +/// holds the lock. +#[tokio::test] +async fn two_prepare_to_serve_runs_under_apply_migrate_once() { + let Some(base) = base_conn() else { + return skip("startup two"); + }; + let s = Scratch::new(&base, "pgs_two").await; + s.load("0.1.14").await; + let holder = s.catalog().await; + let mut tx = holder.begin().await.unwrap(); + hold(&mut tx, "pg_advisory_xact_lock", MIGRATION_KEY).await; + let waiting = AtomicUsize::new(0); + let progress = |line: &str| { + if line.starts_with("taking the migration lock") { + waiting.fetch_add(1, Ordering::SeqCst); + } + }; + let target = Target::at(s.catalog_url()); + let apply = startup(true, Duration::from_secs(60)); + let free = async { + while waiting.load(Ordering::SeqCst) < 2 { + tokio::time::sleep(Duration::from_millis(20)).await; + } + tx.rollback().await.unwrap(); + }; + let (a, b, ()) = tokio::join!( + prepare_to_serve(&PostgresCatalogMigrations, &target, &apply, &progress), + prepare_to_serve(&PostgresCatalogMigrations, &target, &apply, &progress), + free, + ); + holder.close().await; + let mut applied: Vec = [a.expect("first"), b.expect("second")] + .iter() + .map(|p| p.run.as_ref().expect("each took the lock").applied.len()) + .collect(); + applied.sort_unstable(); + assert_eq!( + applied, + [0, step_count()], + "one migrates, and the other takes the lock after it and applies nothing" + ); + let catalog = s.catalog().await; + assert_eq!( + ledger(&catalog).await.len(), + extenddb_storage::migrations::MigrationId::ALL.len() + ); + catalog.close().await; + assert_eq!(s.status().await, CatalogStatus::Current { version: LATEST }); +} + +/// Hold an advisory key of the catalog in `tx`, as another migrator +/// (`pg_advisory_xact_lock` on the migration key) or a running server +/// (`pg_advisory_xact_lock_shared` on the serving key) does. +async fn hold(tx: &mut sqlx::Transaction<'static, sqlx::Postgres>, function: &str, key: i32) { + sqlx::query(&format!("SELECT {function}($1, $2)")) + .bind(NAMESPACE) + .bind(key) + .execute(&mut **tx) + .await + .unwrap(); +} + +/// A zero lock timeout tries each key once. While another migrator holds +/// the migration key, or a server the serving key, the server's run and the +/// run `migrate --yes` makes exit 6 at once, with the catalog unchanged. +/// PostgreSQL reads a `lock_timeout` of 0 as no limit, so a wait would last +/// as long as the holder keeps its key. +#[tokio::test] +async fn a_zero_lock_timeout_tries_each_key_once() { + let Some(base) = base_conn() else { + return skip("startup zero timeout"); + }; + let s = Scratch::new(&base, "pgs_zero").await; + s.load("0.1.14").await; + let before = state(&s).await; + let target = Target::at(s.catalog_url()); + for (function, key) in [ + ("pg_advisory_xact_lock", MIGRATION_KEY), + ("pg_advisory_xact_lock_shared", SERVING_KEY), + ] { + let holder = s.catalog().await; + let mut tx = holder.begin().await.unwrap(); + hold(&mut tx, function, key).await; + let started = Instant::now(); + let served = tokio::time::timeout( + Duration::from_secs(20), + prepare(&s, &startup(true, Duration::ZERO)), + ) + .await + .expect("the server's run waited for the key"); + let err = served.expect_err("locked"); + assert_eq!(err.exit_code(), exit::LOCKED, "{function}: {err:?}"); + let migrated = tokio::time::timeout( + Duration::from_secs(20), + run_with_lock( + &PostgresCatalogMigrations, + &target, + "1.0.0-test", + RunKind::Migrate, + Duration::ZERO, + WhenCurrent::Run, + ), + ) + .await + .expect("migrate --yes waited for the key"); + let err = migrated.expect_err("locked"); + assert_eq!(err.exit_code(), exit::LOCKED, "{function}: {err:?}"); + assert!( + started.elapsed() < Duration::from_secs(10), + "{function}: {:?}", + started.elapsed() + ); + tx.rollback().await.unwrap(); + holder.close().await; + } + assert!(state(&s).await == before, "a run at a zero timeout wrote"); +} + +/// The waits of one run share its lock timeout: a server's run that waits +/// for another migrator's key, and then for a running server's key, exits 6 +/// once the timeout has passed in all, not after a timeout for each wait. +#[tokio::test] +async fn the_waits_of_a_run_share_one_lock_timeout() { + let Some(base) = base_conn() else { + return skip("startup one bound"); + }; + let s = Scratch::new(&base, "pgs_bound").await; + s.load("0.1.14").await; + // A server serves the catalog for the whole test, and another migrator + // holds the migration key for 6 s of the run's 8 s. + let server = s.catalog().await; + let mut serving = server.begin().await.unwrap(); + hold(&mut serving, "pg_advisory_xact_lock_shared", SERVING_KEY).await; + let migrator = s.catalog().await; + let mut migrating = migrator.begin().await.unwrap(); + hold(&mut migrating, "pg_advisory_xact_lock", MIGRATION_KEY).await; + let apply = startup(true, Duration::from_secs(8)); + let started = Instant::now(); + let other_finishes = async { + tokio::time::sleep(Duration::from_secs(6)).await; + migrating.rollback().await.unwrap(); + }; + let (locked, ()) = tokio::join!(prepare(&s, &apply), other_finishes); + let waited = started.elapsed(); + let err = locked.expect_err("locked"); + assert_eq!(err.exit_code(), exit::LOCKED, "{err:?}"); + assert!( + err.to_string() + .starts_with("servers are serving this catalog"), + "{err}" + ); + // 8 s in all, plus the status reads; 8 s for each key would end after + // 14 s. + assert!( + waited >= Duration::from_millis(7500) && waited < Duration::from_secs(13), + "it waited {waited:?}" + ); + serving.rollback().await.unwrap(); + server.close().await; + migrator.close().await; +} diff --git a/crates/storage-sqlite/src/lib.rs b/crates/storage-sqlite/src/lib.rs index 2e1401039..3ca665450 100644 --- a/crates/storage-sqlite/src/lib.rs +++ b/crates/storage-sqlite/src/lib.rs @@ -225,8 +225,9 @@ fn sqlite_server_components_factory( std::sync::Arc::new(lock) }); // The catalog's status is read before the engine opens the file, so - // a server that refuses has written nothing. A dev build migrates - // instead, as `migrate --yes` would, copy included. + // a server that refuses has written nothing. `serve` has applied a + // catalog behind this binary already when its startup policy says + // to; a dev build creates a catalog in a missing or empty file. let dev = options.bootstrap_if_uninitialized; if let Some(lock) = &serve_lock { migrations::prepare_for_serve(&db_path, options.release, lock, dev) diff --git a/crates/storage-sqlite/src/migrations/commands.rs b/crates/storage-sqlite/src/migrations/commands.rs index 51fcc1a41..9d8303727 100644 --- a/crates/storage-sqlite/src/migrations/commands.rs +++ b/crates/storage-sqlite/src/migrations/commands.rs @@ -14,7 +14,8 @@ use extenddb_storage::migrations::{ }; use super::{ - MigrationLock, SqliteMigrations, catalog_status, in_memory_refusal, lock_for_migration, + MigrationLock, SqliteMigrations, catalog_status, holds_tables, in_memory_refusal, + lock_for_migration, }; /// The SQLite backend's catalog migrations for the commands. @@ -51,6 +52,19 @@ impl CatalogMigrations for SqliteCatalogMigrations { std::env::var_os("EXTENDDB__STORAGE__SQLITE__PATH").is_some_and(|v| !v.is_empty()) } + /// An in-memory database, which exists only on the connection of the + /// server that opened it. + fn in_process(&self, target: &Target) -> bool { + matches!(crate::serve_lock::database_file(&target.location), Ok(None)) + } + + /// A dev server creates its catalog in a missing or empty file, and its + /// factory refuses a file that holds tables, another program's database, + /// as `Uninitialized` (`prepare_for_serve`). + async fn server_creates_catalog(&self, target: &Target) -> Result { + Ok(!holds_tables(&target.location).await?) + } + async fn status(&self, target: &Target) -> Result { catalog_status(&target.location).await } diff --git a/crates/storage-sqlite/src/migrations/mod.rs b/crates/storage-sqlite/src/migrations/mod.rs index e784fa82c..c33f41254 100644 --- a/crates/storage-sqlite/src/migrations/mod.rs +++ b/crates/storage-sqlite/src/migrations/mod.rs @@ -242,11 +242,13 @@ pub(crate) async fn migrate_holding( /// Decide whether a server may open the file database at `location`, whose /// lock the server holds: `Current` and `AheadCompatible` serve (the second /// with a warning naming the migrations above this binary's), and in a dev -/// build `Behind` and an `Uninitialized` file with no tables (missing or -/// empty) are migrated first. An `Uninitialized` file that holds tables is -/// another program's database, and is refused as the commands refuse it, -/// naming `extenddb init`, before anything writes to it. Every other status -/// refuses with [`MigrationError::Status`], in a dev build too. +/// build an `Uninitialized` file with no tables (missing or empty) is +/// created first. An `Uninitialized` file that holds tables is another +/// program's database, and is refused as the commands refuse it, naming +/// `extenddb init`, before anything writes to it. Every other status +/// refuses with [`MigrationError::Status`], in a dev build too: `serve` +/// applies a catalog behind this binary before it calls the factory, when +/// its startup policy says to (`[server] catalog_upgrade`). /// /// # Errors /// @@ -270,10 +272,6 @@ pub(crate) async fn prepare_for_serve( log_report(&migrate_holding(location, release, held).await?); Ok(()) } - CatalogStatus::Behind { .. } if dev => { - log_report(&migrate_holding(location, release, held).await?); - Ok(()) - } status => Err(MigrationError::Status(status)), } } diff --git a/crates/storage-sqlite/src/migrations/serve_tests.rs b/crates/storage-sqlite/src/migrations/serve_tests.rs index 5b432edcb..87cc8a932 100644 --- a/crates/storage-sqlite/src/migrations/serve_tests.rs +++ b/crates/storage-sqlite/src/migrations/serve_tests.rs @@ -2,24 +2,31 @@ // SPDX-License-Identifier: Apache-2.0 //! The server factory reads the catalog status before it opens the -//! database: a production build serves only `Current` and `AheadCompatible` -//! and writes nothing when it refuses; a dev build migrates `Uninitialized` -//! and `Behind` first, and refuses the rest; an in-memory database is -//! created by the runner every time. The lock that keeps a migrator, a -//! second migrator and a server apart is tested here too. +//! database: it serves only `Current` and `AheadCompatible` and writes +//! nothing when it refuses; a dev build creates a missing or empty +//! database first; an in-memory database is created by the runner every +//! time. The startup policy `serve` applies before the factory, which +//! migrates a catalog behind the binary under `catalog_upgrade = "apply"`, +//! and the lock that keeps a migrator, a second migrator and a server +//! apart are tested here too. use std::path::Path; +use std::sync::atomic::{AtomicUsize, Ordering}; use std::time::Duration; -use extenddb_storage::migrations::{CatalogStatus, MigrationError, MigrationId, exit}; +use async_trait::async_trait; +use extenddb_storage::migrations::{ + CatalogMigrations, CatalogStatus, HeldLock, LedgerRow, Listed, MigrationError, MigrationId, + Prepared, RunKind, RunReport, Startup, Target, exit, prepare_to_serve, +}; use extenddb_storage::server_components::{ BackendError, ServerComponents, ServerComponentsOptions, }; -use super::migrate; use super::tests::{ DEV_0_1_14, LATEST, RELEASE, copies, exec, load_dump, plain_pool, run, status, temp_db, }; +use super::{SqliteCatalogMigrations, migrate}; const COLLIDING: &str = r#"{"Version":"2012-10-17","Statement":[{"Effect":"Deny","Action":"dynamodb:*","Resource":"*","Condition":{"StringEquals":{"aws:ResourceTag/env":"prod","dynamodb:ResourceTag/env":"dev"}}}]}"#; @@ -125,13 +132,27 @@ async fn a_production_server_refuses_a_released_catalog_and_writes_nothing() { assert!(copies(&db).is_empty()); } +/// A dev build defaults to `catalog_upgrade = "apply"`: `serve` migrates a +/// released catalog through the startup policy, copy included, and the +/// factory then serves it. The factory alone refuses it, as in a +/// production build, so the policy is the one place that migrates. #[tokio::test] async fn a_dev_server_migrates_a_released_catalog_with_its_copy_and_serves() { let db = temp_db("serve-dev-released"); load_dump(&db, DEV_0_1_14).await; + let before = bytes(&db); + let err = refusal(start(&db.to_string_lossy(), true).await); + assert_eq!(err.exit_code(), exit::PENDING, "{err:?}"); + assert_eq!(bytes(&db), before, "the factory wrote to the database"); + let dev = Startup { + creates_uninitialized: true, + ..startup(true, Duration::from_secs(5)) + }; + let prepared = prepare(&db, &dev).await.expect("the policy migrates"); + assert!(!prepared.run.expect("a run").applied.is_empty()); let components = start(&db.to_string_lossy(), true) .await - .expect("a dev server migrates and starts"); + .expect("a dev server starts"); drop(components); assert_eq!( status(&db).await, @@ -144,6 +165,302 @@ async fn a_dev_server_migrates_a_released_catalog_with_its_copy_and_serves() { ); } +fn startup(apply: bool, lock_timeout: Duration) -> Startup<'static> { + Startup { + apply, + creates_uninitialized: false, + release: RELEASE, + lock_timeout, + heartbeat: Startup::HEARTBEAT, + } +} + +/// The startup policy `serve` runs before the factory, on the file at `db`. +async fn prepare(db: &Path, startup: &Startup<'_>) -> Result { + let target = Target::at(db.to_string_lossy()); + prepare_to_serve(&SqliteCatalogMigrations, &target, startup, &|_| {}).await +} + +/// `apply` migrates a released catalog before the server opens it, taking +/// the copy first, and a production server then serves it; `refuse` exits +/// 3 and writes nothing. +#[tokio::test] +async fn apply_migrates_a_released_catalog_before_the_server_opens_it() { + let db = temp_db("startup-apply"); + load_dump(&db, DEV_0_1_14).await; + let before = bytes(&db); + let err = prepare(&db, &startup(false, Duration::from_secs(5))) + .await + .expect_err("refused"); + assert_eq!(err.exit_code(), exit::PENDING, "{err:?}"); + assert_eq!(bytes(&db), before, "refuse wrote to the database"); + assert!(copies(&db).is_empty()); + + let prepared = prepare(&db, &startup(true, Duration::from_secs(5))) + .await + .expect("applied"); + let report = prepared.run.expect("a run"); + assert_eq!(report.from, None); + assert_eq!(report.to, Some(LATEST)); + assert_eq!(report.applied.len(), MigrationId::ALL.len()); + assert_eq!(copies(&db).len(), 1, "the copy is taken before the run"); + drop( + start(&db.to_string_lossy(), false) + .await + .expect("a production server serves the migrated catalog"), + ); + assert_eq!( + status(&db).await, + CatalogStatus::Current { version: LATEST } + ); +} + +#[tokio::test] +async fn apply_on_a_current_catalog_writes_nothing() { + let db = temp_db("startup-current"); + current_catalog(&db).await; + let before = bytes(&db); + let prepared = prepare(&db, &startup(true, Duration::from_secs(5))) + .await + .expect("served"); + assert_eq!(prepared, Prepared::default()); + assert_eq!(bytes(&db), before, "a current catalog was written to"); + assert!(copies(&db).is_empty()); +} + +#[tokio::test] +async fn apply_on_a_catalog_that_needs_attention_exits_5_and_writes_nothing() { + let db = temp_db("startup-attention"); + load_dump(&db, DEV_0_1_14).await; + collide(&db).await; + let before = bytes(&db); + let err = prepare(&db, &startup(true, Duration::from_secs(5))) + .await + .expect_err("refused"); + assert!( + matches!( + err, + MigrationError::Status(CatalogStatus::NeedsAttention { .. }) + ), + "{err:?}" + ); + assert_eq!(err.exit_code(), exit::ATTENTION); + assert_eq!(bytes(&db), before); + assert!(copies(&db).is_empty()); +} + +/// Another process holds the database's lock: `apply` waits for it up to +/// the timeout, then exits 6 with the catalog still behind and unchanged. +#[cfg(unix)] +#[tokio::test] +async fn apply_waits_for_a_held_lock_and_exits_6() { + let db = temp_db("startup-locked"); + load_dump(&db, DEV_0_1_14).await; + let before = bytes(&db); + let holder = crate::serve_lock::ServeLock::acquire(&db).expect("another process's lock"); + let started = std::time::Instant::now(); + let err = prepare(&db, &startup(true, Duration::from_millis(800))) + .await + .expect_err("locked"); + assert!( + started.elapsed() >= Duration::from_millis(700), + "it waited {:?}", + started.elapsed() + ); + assert!(matches!(err, MigrationError::Locked(_)), "{err:?}"); + assert_eq!(err.exit_code(), exit::LOCKED); + assert_eq!(bytes(&db), before); + assert!(copies(&db).is_empty()); + drop(holder); +} + +/// Two `prepare_to_serve` runs under `apply` on a released catalog, both +/// waiting for a lock another process holds, as the checks of two servers +/// started together do after their first status read: once it is free, one +/// migrates the catalog, and the other takes the lock after it and applies +/// nothing. The servers are not started here; one of two servers started +/// together can exit 6 when it registers while the other holds the lock. +#[cfg(unix)] +#[tokio::test] +async fn two_prepare_to_serve_runs_under_apply_migrate_once() { + let db = temp_db("startup-two"); + load_dump(&db, DEV_0_1_14).await; + let holder = crate::serve_lock::ServeLock::acquire(&db).expect("another process's lock"); + let waiting = AtomicUsize::new(0); + let progress = |line: &str| { + if line.starts_with("taking the migration lock") { + waiting.fetch_add(1, Ordering::SeqCst); + } + }; + let target = Target::at(db.to_string_lossy()); + let apply = startup(true, Duration::from_secs(60)); + let free = async { + while waiting.load(Ordering::SeqCst) < 2 { + tokio::time::sleep(Duration::from_millis(20)).await; + } + drop(holder); + }; + let (a, b, ()) = tokio::join!( + prepare_to_serve(&SqliteCatalogMigrations, &target, &apply, &progress), + prepare_to_serve(&SqliteCatalogMigrations, &target, &apply, &progress), + free, + ); + let mut applied: Vec = [a.expect("first"), b.expect("second")] + .iter() + .map(|p| p.run.as_ref().expect("each took the lock").applied.len()) + .collect(); + applied.sort_unstable(); + assert_eq!( + applied, + [0, MigrationId::ALL.len()], + "one migrates, and the other takes the lock after it and applies nothing" + ); + assert_eq!(copies(&db).len(), 1); + assert_eq!( + status(&db).await, + CatalogStatus::Current { version: LATEST } + ); +} + +/// The SQLite backend, counting the runs it is asked to make. +#[derive(Default)] +struct CountingRuns { + runs: AtomicUsize, +} + +#[async_trait] +impl CatalogMigrations for CountingRuns { + fn listed(&self, id: MigrationId) -> Listed { + SqliteCatalogMigrations.listed(id) + } + fn backup_advice(&self, target: &Target) -> String { + SqliteCatalogMigrations.backup_advice(target) + } + fn in_process(&self, target: &Target) -> bool { + SqliteCatalogMigrations.in_process(target) + } + async fn server_creates_catalog(&self, target: &Target) -> Result { + SqliteCatalogMigrations.server_creates_catalog(target).await + } + async fn status(&self, target: &Target) -> Result { + SqliteCatalogMigrations.status(target).await + } + async fn catalog_ledger(&self, target: &Target) -> Result, MigrationError> { + SqliteCatalogMigrations.catalog_ledger(target).await + } + async fn lock(&self, target: &Target, timeout: Duration) -> Result { + SqliteCatalogMigrations.lock(target, timeout).await + } + async fn run( + &self, + lock: &HeldLock, + release: &str, + kind: RunKind, + ) -> Result { + self.runs.fetch_add(1, Ordering::SeqCst); + SqliteCatalogMigrations.run(lock, release, kind).await + } + async fn forget(&self, lock: &HeldLock, id: u32) -> Result<(), MigrationError> { + SqliteCatalogMigrations.forget(lock, id).await + } +} + +/// Another process migrates the catalog while this one waits for the lock: +/// under the lock this one finds it current, and releases the lock and +/// serves it without the backend's run, so it writes nothing to the +/// database and takes no copy. +#[cfg(unix)] +#[tokio::test] +async fn a_catalog_migrated_during_the_wait_is_served_with_nothing_written() { + let db = temp_db("startup-migrated-meanwhile"); + load_dump(&db, DEV_0_1_14).await; + let location = db.to_string_lossy().into_owned(); + let other = crate::serve_lock::ServeLock::acquire(&db).expect("another process's lock"); + let backend = CountingRuns::default(); + let waiting = AtomicUsize::new(0); + let progress = |line: &str| { + if line.starts_with("taking the migration lock") { + waiting.fetch_add(1, Ordering::SeqCst); + } + }; + let target = Target::at(location.as_str()); + let apply = startup(true, Duration::from_secs(60)); + let other_process = async { + while waiting.load(Ordering::SeqCst) < 1 { + tokio::time::sleep(Duration::from_millis(20)).await; + } + super::migrate_holding(&location, RELEASE, &other) + .await + .expect("the other process migrates"); + let written = (bytes(&db), copies(&db)); + drop(other); + written + }; + let (prepared, (after_other, copies_after_other)) = tokio::join!( + prepare_to_serve(&backend, &target, &apply, &progress), + other_process, + ); + let report = prepared.expect("served").run.expect("a run under the lock"); + assert!(report.applied.is_empty(), "{report:?}"); + assert_eq!(report.to, Some(LATEST)); + assert_eq!(backend.runs.load(Ordering::SeqCst), 0, "the backend ran"); + assert_eq!(bytes(&db), after_other, "the waiting process wrote"); + assert_eq!(copies(&db), copies_after_other); + assert_eq!(copies(&db).len(), 1, "only the other process's copy"); + assert_eq!( + status(&db).await, + CatalogStatus::Current { version: LATEST } + ); +} + +/// A dev build's policy refuses, before the server starts, a file that +/// holds another program's tables, with the refusal the server's factory +/// gives it, and writes nothing; an empty file is left to the server, which +/// creates the catalog in it. +#[tokio::test] +async fn a_dev_policy_refuses_a_file_that_holds_another_programs_tables() { + let db = temp_db("startup-dev-foreign"); + exec( + &db, + "CREATE TABLE notes (id INTEGER PRIMARY KEY, body TEXT)", + ) + .await; + let before = bytes(&db); + let dev = Startup { + creates_uninitialized: true, + ..startup(true, Duration::from_secs(5)) + }; + let err = prepare(&db, &dev).await.expect_err("refused"); + assert_eq!(err, MigrationError::Status(CatalogStatus::Uninitialized)); + assert_eq!(err.exit_code(), exit::ERROR); + assert_eq!(err, refusal(start(&db.to_string_lossy(), true).await)); + assert_eq!(bytes(&db), before, "the policy wrote to the file"); + assert!(copies(&db).is_empty()); + + let empty = temp_db("startup-dev-empty"); + std::fs::write(&empty, b"").expect("an empty file"); + let prepared = prepare(&empty, &dev).await.expect("left to the server"); + assert_eq!(prepared, Prepared::default()); +} + +/// An in-memory database belongs to the server that opens it: the policy +/// reads nothing, and the server creates the catalog. +#[tokio::test] +async fn an_in_memory_database_is_left_to_its_server() { + let target = Target::at(":memory:"); + assert!(SqliteCatalogMigrations.in_process(&target)); + assert!(!SqliteCatalogMigrations.in_process(&Target::at("/srv/x.sqlite"))); + let prepared = prepare_to_serve( + &SqliteCatalogMigrations, + &target, + &startup(true, Duration::from_secs(5)), + &|_| {}, + ) + .await + .expect("left to the server"); + assert_eq!(prepared, Prepared::default()); +} + #[tokio::test] async fn a_dev_server_creates_a_missing_catalog_and_its_rows() { let db = temp_db("serve-dev-missing"); @@ -164,11 +481,10 @@ async fn a_dev_server_creates_a_missing_catalog_and_its_rows() { assert!(copies(&db).is_empty(), "a new database has nothing to copy"); } -#[tokio::test] -async fn a_dev_server_refuses_a_catalog_that_needs_attention() { - let db = temp_db("serve-dev-attention"); - load_dump(&db, DEV_0_1_14).await; - let pool = plain_pool(&db).await; +/// Give a released catalog's first IAM user a policy migration 2 cannot +/// rewrite, so its status is `NeedsAttention`. +async fn collide(db: &Path) { + let pool = plain_pool(db).await; let (account, user): (String, String) = sqlx::query_as("SELECT account_id, user_name FROM iam_users LIMIT 1") .fetch_one(&pool) @@ -185,6 +501,13 @@ async fn a_dev_server_refuses_a_catalog_that_needs_attention() { .await .expect("policy"); pool.close().await; +} + +#[tokio::test] +async fn a_dev_server_refuses_a_catalog_that_needs_attention() { + let db = temp_db("serve-dev-attention"); + load_dump(&db, DEV_0_1_14).await; + collide(&db).await; let before = bytes(&db); let err = refusal(start(&db.to_string_lossy(), true).await); assert!( diff --git a/crates/storage/src/migrations/advice.rs b/crates/storage/src/migrations/advice.rs index a93528b7a..1f21aa89c 100644 --- a/crates/storage/src/migrations/advice.rs +++ b/crates/storage/src/migrations/advice.rs @@ -33,6 +33,10 @@ pub struct Advice<'a> { /// store wherever it runs and whatever `extenddb.toml` the directory /// holds. pub assignment: Option<&'a str>, + /// The message is a server's refusal: for a catalog behind the binary + /// it also names `serve --migrate`, which applies the migrations at + /// startup. + pub serving: bool, } impl Advice<'_> { @@ -101,6 +105,7 @@ pub struct AdviceFor { backup: String, config: Option, assignment: Option, + serving: bool, } impl AdviceFor { @@ -133,9 +138,17 @@ impl AdviceFor { }) }) .and_then(|m| m.location_assignment(target)), + serving: false, } } + /// The advice for a server's refusal ([`Advice::serving`]). + #[must_use] + pub fn for_server(mut self) -> Self { + self.serving = true; + self + } + /// The advice, borrowing these values. #[must_use] pub fn advice(&self) -> Advice<'_> { @@ -145,6 +158,7 @@ impl AdviceFor { backup: &self.backup, config: self.config.as_deref(), assignment: self.assignment.as_deref(), + serving: self.serving, } } } @@ -174,14 +188,18 @@ pub fn status_message(status: &CatalogStatus, advice: &Advice<'_>) -> String { is not detected while it runs.", ), }; - format!( + let mut message = format!( "{at}, and ExtendDB {release} needs migration {latest}.\n{}\n{stop}\n{backup}, \ then run:\n{}", pending_line(pending), advice.command("--yes"), release = advice.release, backup = capitalized(advice.backup), - ) + ); + if advice.serving { + message.push_str("\nor start this server with --migrate."); + } + message } // `init --config ` refuses a config file that exists, and this // catalog was found through one, so the command is named alone. @@ -291,7 +309,7 @@ pub fn stores_label(pending: &Pending, stores: usize) -> String { /// `Pending (all breaking): 2 name (catalog), ...`, or each kind beside its /// migration when the kinds differ. -fn pending_line(pending: &[Pending]) -> String { +pub(crate) fn pending_line(pending: &[Pending]) -> String { let groups = grouped(pending); let same = groups.windows(2).all(|w| w[0].0.kind == w[1].0.kind); let items: Vec = groups @@ -329,6 +347,7 @@ mod tests { backup: "back up the SQLite database file /var/lib/extenddb/extenddb.sqlite", config: Some("/etc/extenddb/extenddb.toml"), assignment: None, + serving: false, }; fn pending(kind: Kind) -> Vec { @@ -374,6 +393,48 @@ mod tests { ); } + /// A server's refusal of a catalog behind it ends with the other way to + /// apply the migrations, starting the server with `--migrate`. `migrate` + /// and `verify` print the same message without that line. + #[test] + fn a_server_refusing_a_catalog_behind_it_names_migrate() { + let status = CatalogStatus::Behind { + version: Some(1), + pending: pending(Kind::Breaking), + }; + let serving = Advice { + serving: true, + ..ADVICE + }; + let message = status_message(&status, &serving); + assert!( + message.ends_with( + "\n extenddb migrate --config /etc/extenddb/extenddb.toml --yes\nor start this \ + server with --migrate." + ), + "{message}" + ); + assert!(!status_message(&status, &ADVICE).contains("--migrate")); + // Only a catalog behind the binary can be migrated at startup: every + // other refusal is the same for a server. + let attention = CatalogStatus::NeedsAttention { + items: vec!["migration 2: a collision".to_owned()], + }; + assert_eq!( + status_message(&attention, &serving), + status_message(&attention, &ADVICE) + ); + let shown = super::AdviceFor::new( + "1.0.1", + "/srv/x.sqlite".to_owned(), + None, + &crate::migrations::Target::at("/srv/x.sqlite"), + Some("/etc/extenddb/extenddb.toml"), + ); + assert!(!shown.advice().serving); + assert!(shown.for_server().advice().serving); + } + #[test] fn a_catalog_with_no_ledger_says_to_stop_every_server() { let message = status_message( diff --git a/crates/storage/src/migrations/advice_tests.rs b/crates/storage/src/migrations/advice_tests.rs index a9746bce9..d46eefb94 100644 --- a/crates/storage/src/migrations/advice_tests.rs +++ b/crates/storage/src/migrations/advice_tests.rs @@ -114,6 +114,7 @@ fn the_config_path_is_quoted_for_a_posix_shell() { backup: "back up /srv/x.sqlite", config: Some("/srv/sp ace's dir/extenddb.toml"), assignment: None, + serving: false, }; assert_eq!( advised(&written_by_older_release(), &advice), diff --git a/crates/storage/src/migrations/catalog.rs b/crates/storage/src/migrations/catalog.rs index 4c85389c8..0e2ff4f62 100644 --- a/crates/storage/src/migrations/catalog.rs +++ b/crates/storage/src/migrations/catalog.rs @@ -185,6 +185,28 @@ pub trait CatalogMigrations: Send + Sync { false } + /// Whether the store at `target` exists only inside the server process + /// that opens it, as an in-memory SQLite database does: that server + /// creates the catalog when it starts, and no other process can read + /// its status, so `serve` reads none before it starts. Opens nothing; + /// `false` (the default) for every store another process can open. + fn in_process(&self, target: &Target) -> bool { + let _ = target; + false + } + + /// Whether a dev build's server creates its catalog in the store at + /// `target`, whose status is `Uninitialized`. `true` (the default) when + /// the backend's server factory creates the catalog in any such store. + /// A backend whose factory refuses an uninitialized store that holds + /// another program's data, as `Uninitialized`, returns `false` for one + /// (SQLite: a database file with tables), so `serve` refuses it before + /// it forks with the refusal the factory gives after. Read-only. + async fn server_creates_catalog(&self, target: &Target) -> Result { + let _ = target; + Ok(true) + } + /// The catalog status. Takes no lock and writes nothing, so it runs /// beside a server. async fn status(&self, target: &Target) -> Result; @@ -232,10 +254,11 @@ pub trait CatalogMigrations: Send + Sync { } /// Notes about the deployment that its status does not show, for the - /// preview and `verify` to print and `migrate --yes` to check before it - /// takes the lock ([`before_lock`]). On PostgreSQL: tables and sequences - /// the application role does not own. Read-only, like the status. None - /// by default. + /// preview and `verify` to print, and for `migrate --yes` and a server + /// under `catalog_upgrade = "apply"` to check before they take the lock + /// ([`before_lock`]). On PostgreSQL: tables and sequences the + /// application role does not own. Read-only, like the status. None by + /// default. async fn status_notes(&self, target: &Target) -> Result, MigrationError> { let _ = target; Ok(Vec::new()) @@ -305,16 +328,19 @@ pub async fn policy_rewrite_lines( pub struct StatusNote { /// The line the preview and `verify` print. pub text: String, - /// Whether `migrate --yes` refuses before it takes the lock while the - /// note holds and the run would apply something. + /// Whether `migrate --yes`, and a server under `catalog_upgrade = + /// "apply"`, refuse before they take the lock while the note holds and + /// the run would apply something. pub refuses_runs: bool, } -/// What `migrate --yes` checks before it takes the lock: the backend's -/// status notes, returned for the operator to read, or a refusal (exit 1) -/// when a note refuses runs and the run would apply something, which is -/// every `--reconverge` and a `migrate` whose status is not `Current` or -/// `AheadCompatible`. `init` creates its objects and checks nothing. +/// What `migrate --yes`, and a server under `catalog_upgrade = "apply"`, +/// check before they take the lock: the backend's status notes, returned +/// for the operator to read, or a refusal (exit 1) when a note refuses runs +/// and the run would apply something, which is every `--reconverge` and a +/// `migrate` whose status is not `Current` or `AheadCompatible`. The +/// refusal names `command`, the command that checks (`migrate --yes`). +/// `init` creates its objects and checks nothing. /// /// # Errors /// @@ -324,6 +350,7 @@ pub async fn before_lock( migrations: &dyn CatalogMigrations, target: &Target, kind: RunKind, + command: &str, ) -> Result, MigrationError> { if kind == RunKind::Create { return Ok(Vec::new()); @@ -349,7 +376,7 @@ pub async fn before_lock( // One note per line, as the preview prints them, so the statements // each note ends with can be copied on their own. Err(MigrationError::Refused(format!( - "migrate --yes refuses to apply migrations while these notes hold:\n{}\nNothing was \ + "{command} refuses to apply migrations while these notes hold:\n{}\nNothing was \ changed and no lock was taken.", refusing .iter() @@ -374,8 +401,48 @@ pub async fn run_locked( lock: &HeldLock, release: &str, kind: RunKind, +) -> Result { + locked_run(migrations, target, lock, release, kind, WhenCurrent::Run).await +} + +/// What [`run_with_lock`] does with a `migrate` run when the status it +/// reads under the lock is `Current` or `AheadCompatible`, so the run has +/// nothing to apply. +#[derive(Debug, Clone, Copy, PartialEq, Eq)] +pub enum WhenCurrent { + /// Call the backend's run, which records nothing and makes the steps + /// the backend takes beside the ledger on every run (PostgreSQL's + /// pgvector attempt): `migrate --yes`. + Run, + /// Release the lock without calling the backend's run, and return a + /// report with no step: a server starting under `catalog_upgrade = + /// "apply"`, which serves the catalog as it is. + Release, +} + +/// [`run_locked`], returning a report with no step instead of calling the +/// backend's run when `when_current` says so and the status under the lock +/// leaves a `migrate` run nothing to apply. +async fn locked_run( + migrations: &dyn CatalogMigrations, + target: &Target, + lock: &HeldLock, + release: &str, + kind: RunKind, + when_current: WhenCurrent, ) -> Result { let status = migrations.status_under_lock(lock, target).await?; + if when_current == WhenCurrent::Release + && kind == RunKind::Migrate + && let CatalogStatus::Current { version } | CatalogStatus::AheadCompatible { version, .. } = + &status + { + return Ok(RunReport { + from: Some(*version), + to: Some(*version), + ..RunReport::default() + }); + } run_with_status(migrations, &status, lock, release, kind).await } @@ -399,6 +466,31 @@ pub async fn run_with_status( migrations.run(lock, release, kind).await } +/// Take the migration lock for `target`, waiting up to `timeout` for +/// another migration and for running servers, run `kind` under it +/// ([`run_locked`]), and release it on every exit path. `migrate --yes` +/// and a server starting under `catalog_upgrade = "apply"` both run this; +/// `when_current` says what a `migrate` run does when the status under the +/// lock leaves it nothing to apply. +/// +/// # Errors +/// +/// [`MigrationError::Locked`] (exit 6) when the lock or a running server +/// outlasted `timeout`, or as [`run_locked`]. +pub async fn run_with_lock( + migrations: &dyn CatalogMigrations, + target: &Target, + release: &str, + kind: RunKind, + timeout: Duration, + when_current: WhenCurrent, +) -> Result { + let lock = migrations.lock(target, timeout).await?; + let report = locked_run(migrations, target, &lock, release, kind, when_current).await; + migrations.release(lock).await; + report +} + /// Delete the ledger rows of `id` under `lock`, which `migrations` took for /// `target`, after reading the status under the lock as [`run_locked`] /// does: a store that is not a catalog (`Uninitialized`) is refused, naming diff --git a/crates/storage/src/migrations/mod.rs b/crates/storage/src/migrations/mod.rs index aca1136e2..1bc871307 100644 --- a/crates/storage/src/migrations/mod.rs +++ b/crates/storage/src/migrations/mod.rs @@ -14,6 +14,8 @@ //! - [`Runner::status`] computes the [`CatalogStatus`] that `serve`, //! `migrate` and `verify` act on, and [`CatalogStatus::exit_code`] maps it //! to the process exit status. +//! - [`prepare_to_serve`] is what `serve` does with the status before it +//! opens the catalog, by its startup policy (`[server] catalog_upgrade`). //! //! A backend implements [`MigrationBackend`]: reading and writing its ledgers, //! running one body inside one store's commit, and whatever its store needs @@ -28,6 +30,7 @@ mod ledger; mod record; mod registry; mod runner; +mod startup; mod status; mod table; @@ -39,9 +42,9 @@ pub mod m0002_resource_tag_condition_keys; pub use backend::{MigrationBackend, Step, StoreRef}; pub use catalog::{ - AdminRole, CatalogMigrations, HeldLock, Listed, RunKind, StatusNote, Target, before_lock, - binary_catalog_label, forget_locked, installed, policy_rewrite_lines, policy_rewrite_pending, - run_locked, run_with_status, + AdminRole, CatalogMigrations, HeldLock, Listed, RunKind, StatusNote, Target, WhenCurrent, + before_lock, binary_catalog_label, forget_locked, installed, policy_rewrite_lines, + policy_rewrite_pending, run_locked, run_with_lock, run_with_status, }; #[cfg(any(test, feature = "test-util"))] pub use checksum::check_released; @@ -51,6 +54,7 @@ pub use ledger::{CatalogTraces, LedgerColumns, LedgerRow, Outcome}; pub use record::{LedgerWrites, in_transaction, record_rows, sql_ledger_ddl}; pub use registry::{MigrationId, RELEASED_THROUGH}; pub use runner::Runner; +pub use startup::{Prepared, Startup, prepare_to_serve}; pub use status::{ AppliedStep, CatalogStatus, MigrationError, Pending, RunReport, behind_line, exit, stores_behind, diff --git a/crates/storage/src/migrations/startup.rs b/crates/storage/src/migrations/startup.rs new file mode 100644 index 000000000..808768c58 --- /dev/null +++ b/crates/storage/src/migrations/startup.rs @@ -0,0 +1,275 @@ +// Copyright 2026 ExtendDB contributors +// SPDX-License-Identifier: Apache-2.0 + +//! What `serve` does with the catalog before it opens it: the startup +//! policy, `[server] catalog_upgrade`, which `serve --migrate` sets to +//! `apply` for one run. +//! +//! The status is read with no lock. `Current` serves, and so does +//! `AheadCompatible`, with a warning. Under `apply` a catalog behind this +//! binary is migrated first: the status notes `migrate --yes` checks before +//! it takes the lock ([`before_lock`]), then the run `migrate --yes` makes +//! ([`run_with_lock`]): the migration lock, which waits for another +//! migration and for running servers, the status read again under it, so a +//! catalog another process migrated meanwhile is served as it is without +//! the backend's run, `detect` for every pending code body before the first +//! write, the SQLite copy, the runner, and the release. Under `refuse`, and +//! under `apply` for every other status, the server stops with the status's +//! exit code: no setting serves a catalog this binary cannot use. +//! +//! A dev build serves a store that is not a catalog yet, which its server +//! creates, unless the backend's server refuses that store +//! ([`CatalogMigrations::server_creates_catalog`]). A store that exists only +//! inside the server (an in-memory SQLite database) is created by the +//! server when it starts and is not read here. + +use std::time::Duration; + +use tokio::time::Instant; + +use super::advice::pending_line; +use super::catalog::{CatalogMigrations, RunKind, Target, WhenCurrent, before_lock, run_with_lock}; +use super::registry::MigrationId; +use super::status::{CatalogStatus, MigrationError, RunReport}; + +/// How a server starts on the catalog. +#[derive(Debug, Clone, Copy)] +pub struct Startup<'a> { + /// Apply the migrations of a catalog behind this binary instead of + /// refusing it (`catalog_upgrade = "apply"`). + pub apply: bool, + /// Leave a store that is not a catalog yet to the server, which creates + /// it: a dev build, which needs no `init`. A store the backend's server + /// would refuse ([`CatalogMigrations::server_creates_catalog`]) is + /// refused here. + pub creates_uninitialized: bool, + /// The ExtendDB release, recorded in the ledger rows the run writes. + pub release: &'a str, + /// How long the run waits for the migration lock and for running + /// servers before it stops with exit 6. + pub lock_timeout: Duration, + /// How often a line says that the run is still going. Greater than + /// zero. + pub heartbeat: Duration, +} + +impl Startup<'_> { + /// How often a server says that its run is still going: well inside + /// the 15 s the npm launcher waits after the last such line. + pub const HEARTBEAT: Duration = Duration::from_secs(5); +} + +/// What [`prepare_to_serve`] did. +#[derive(Debug, Clone, Default, PartialEq, Eq)] +pub struct Prepared { + /// What the run under the migration lock did, or `None` when no run was + /// made. A report with no step applied means another process applied + /// the migrations while this one waited for the lock. + pub run: Option, + /// For the operator: the catalog is ahead of this binary by additive + /// migrations only, which this binary serves. + pub warning: Option, +} + +/// The command a refusal before the lock names on the server's path. +const SERVER_APPLYING: &str = "serve with --migrate or catalog_upgrade = \"apply\""; + +/// The line before the first status read. +const READING: &str = "reading the catalog status"; + +/// The line before the status read that follows a wait that reached the +/// lock timeout. +const READING_AGAIN: &str = "the wait reached the lock timeout; reading the catalog status again"; + +/// Read the status of the catalog at `target` and decide whether a server +/// may open it, applying its pending migrations first when `startup` says +/// so. `progress` receives the lines the server prints on stderr: one +/// before the status is read; for a run, the pending migrations, the status +/// notes the run checks before the lock, the wait for the lock, and one +/// line every [`Startup::heartbeat`] while the run goes on; and when the +/// run ends, the lines of what it did: the SQLite copy, each migration it +/// applied, and the migration the catalog is at. +/// +/// # Errors +/// +/// [`MigrationError::Status`] with the status a server refuses, which +/// carries its exit code; [`MigrationError::Refused`] (exit 1) when a status +/// note refuses the run ([`before_lock`]); [`MigrationError::Locked`] +/// (exit 6) when the lock or a running server outlasted the timeout and the +/// catalog is still behind; or as [`run_with_lock`]. +pub async fn prepare_to_serve( + migrations: &dyn CatalogMigrations, + target: &Target, + startup: &Startup<'_>, + progress: &(dyn Fn(&str) + Send + Sync), +) -> Result { + if migrations.in_process(target) { + return Ok(Prepared::default()); + } + // The read runs `detect` for every pending code body, which can take a + // while on a large catalog. + progress(READING); + let status = migrations.status(target).await?; + match &status { + CatalogStatus::Current { .. } => Ok(Prepared::default()), + CatalogStatus::AheadCompatible { .. } => Ok(served_ahead(&status)), + CatalogStatus::Uninitialized if startup.creates_uninitialized => { + if migrations.server_creates_catalog(target).await? { + Ok(Prepared::default()) + } else { + Err(MigrationError::Status(CatalogStatus::Uninitialized)) + } + } + CatalogStatus::Behind { version, pending } if startup.apply => { + let latest = MigrationId::LATEST.number(); + progress(&match version { + Some(v) => format!( + "the catalog is at migration {v} and this binary needs migration {latest}; \ + applying the pending migrations before the server starts" + ), + None => format!( + "the catalog has no migration ledger (a release before 1.0 created it); \ + applying migrations 1 to {latest} before the server starts" + ), + }); + progress(&pending_line(pending)); + // The notes `migrate --yes` checks before it takes the lock: a + // note that refuses runs stops the server here, before any + // change, with the refusal `migrate --yes` gives. + for note in before_lock(migrations, target, RunKind::Migrate, SERVER_APPLYING).await? { + progress(&format!("note: {}", note.text)); + } + apply(migrations, target, startup, progress).await + } + _ => Err(MigrationError::Status(status)), + } +} + +/// A catalog ahead of this binary by additive migrations, which it serves. +fn served_ahead(status: &CatalogStatus) -> Prepared { + Prepared { + run: None, + warning: Some(format!( + "{status}; serving it, because a binary may serve migrations it does not know when \ + every one of them is additive" + )), + } +} + +/// The run under the lock, with a line every heartbeat while it goes on. +async fn apply( + migrations: &dyn CatalogMigrations, + target: &Target, + startup: &Startup<'_>, + progress: &(dyn Fn(&str) + Send + Sync), +) -> Result { + progress(&format!( + "taking the migration lock, waiting up to {} s for a server or another migration", + startup.lock_timeout.as_secs() + )); + let started = Instant::now(); + // A catalog that another process migrated while this one waited is + // served as it is: the backend's run, which on PostgreSQL makes the + // pgvector attempt and opens the runner's sessions, is not called. + let run = run_with_lock( + migrations, + target, + startup.release, + RunKind::Migrate, + startup.lock_timeout, + WhenCurrent::Release, + ); + let mut run = std::pin::pin!(run); + let mut heartbeat = tokio::time::interval_at(started + startup.heartbeat, startup.heartbeat); + let result = loop { + tokio::select! { + result = &mut run => break result, + _ = heartbeat.tick() => { + progress(&format!("in progress for {} s", started.elapsed().as_secs())); + } + } + }; + match result { + Ok(report) => { + for line in report_lines(&report) { + progress(&line); + } + // A run that applied nothing found the catalog migrated by + // another process, which may have left it ahead of this binary + // by additive migrations: the status says so, as `migrate --yes` + // reads it after such a run. + let warning = if report.applied.is_empty() { + ahead_warning(migrations, target).await + } else { + None + }; + Ok(Prepared { + run: Some(report), + warning, + }) + } + // A process that migrated the catalog while this one waited, and + // then started serving it, holds what the lock waits for. The + // catalog then needs nothing, and the server starts as `serve` + // would on it; the server's own checks decide whether it may. + Err(MigrationError::Locked(message)) => { + progress(READING_AGAIN); + match migrations.status(target).await { + Ok(CatalogStatus::Current { .. }) => { + progress(MIGRATED_ELSEWHERE); + Ok(Prepared::default()) + } + Ok(status @ CatalogStatus::AheadCompatible { .. }) => { + progress(MIGRATED_ELSEWHERE); + Ok(served_ahead(&status)) + } + _ => Err(MigrationError::Locked(message)), + } + } + Err(error) => Err(error), + } +} + +/// The warning for a catalog ahead of this binary by additive migrations, +/// read after a run that applied nothing. `None` for any other status, and +/// when the read fails: the server reads the status again when it +/// registers. +async fn ahead_warning(migrations: &dyn CatalogMigrations, target: &Target) -> Option { + match migrations.status(target).await { + Ok(status @ CatalogStatus::AheadCompatible { .. }) => served_ahead(&status).warning, + _ => None, + } +} + +/// The line for a run that found the catalog migrated by another process. +const MIGRATED_ELSEWHERE: &str = + "nothing to apply: another process migrated the catalog while this one waited for the lock"; + +/// What a run did, one line each: the backend's lines (the SQLite copy's +/// path), each step with its notes indented below it, and the version the +/// catalog is at. +fn report_lines(report: &RunReport) -> Vec { + let mut lines = report.notes.clone(); + let several = report + .applied + .windows(2) + .any(|w| w[0].store_name != w[1].store_name); + for step in &report.applied { + lines.push(if several { + format!("applied {} {} in {}", step.id, step.name, step.store_name) + } else { + format!("applied {} {}", step.id, step.name) + }); + lines.extend(step.notes.iter().map(|note| format!(" {note}"))); + } + if report.applied.is_empty() { + lines.push(MIGRATED_ELSEWHERE.to_owned()); + } else if let Some(to) = report.to { + lines.push(format!("the catalog is at migration {to}")); + } + lines +} + +#[cfg(test)] +#[path = "startup_tests.rs"] +mod tests; diff --git a/crates/storage/src/migrations/startup_tests.rs b/crates/storage/src/migrations/startup_tests.rs new file mode 100644 index 000000000..049fec0d5 --- /dev/null +++ b/crates/storage/src/migrations/startup_tests.rs @@ -0,0 +1,549 @@ +// Copyright 2026 ExtendDB contributors +// SPDX-License-Identifier: Apache-2.0 + +//! The startup policy on a backend that records what it is asked: which +//! statuses serve, refuse or migrate, when the lock is taken, and the lines +//! a run prints. + +use std::collections::VecDeque; +use std::sync::Mutex; +use std::time::Duration; + +use async_trait::async_trait; + +use super::{MIGRATED_ELSEWHERE, Prepared, READING, Startup, prepare_to_serve}; +use crate::migrations::{ + AppliedStep, CatalogMigrations, CatalogStatus, HeldLock, Kind, LedgerRow, Listed, + MigrationError, MigrationId, Pending, RunKind, RunReport, StatusNote, StoreKind, Target, exit, +}; + +struct Fake { + /// The statuses the next reads return, the last one repeated. + statuses: Mutex>, + lock: Result<(), MigrationError>, + report: RunReport, + run_takes: Duration, + in_process: bool, + /// What `server_creates_catalog` answers. + creates: bool, + notes: Vec, + calls: Mutex>, +} + +impl Fake { + fn new(statuses: &[CatalogStatus]) -> Self { + Self { + statuses: Mutex::new(statuses.iter().cloned().collect()), + lock: Ok(()), + report: applied_report(), + run_takes: Duration::ZERO, + in_process: false, + creates: true, + notes: Vec::new(), + calls: Mutex::new(Vec::new()), + } + } + + fn calls(&self) -> Vec<&'static str> { + self.calls.lock().unwrap().clone() + } + + fn call(&self, name: &'static str) { + self.calls.lock().unwrap().push(name); + } +} + +#[async_trait] +impl CatalogMigrations for Fake { + fn listed(&self, _id: MigrationId) -> Listed { + Listed::NotApplicable("fake") + } + fn backup_advice(&self, target: &Target) -> String { + format!("back up {}", target.location) + } + fn in_process(&self, _target: &Target) -> bool { + self.in_process + } + async fn server_creates_catalog(&self, _target: &Target) -> Result { + self.call("creates"); + Ok(self.creates) + } + async fn status(&self, _target: &Target) -> Result { + self.call("status"); + let mut statuses = self.statuses.lock().unwrap(); + let status = statuses.front().cloned().expect("a status"); + if statuses.len() > 1 { + statuses.pop_front(); + } + Ok(status) + } + async fn catalog_ledger(&self, _: &Target) -> Result, MigrationError> { + Ok(Vec::new()) + } + async fn lock(&self, target: &Target, _: Duration) -> Result { + self.call("lock"); + self.lock + .clone() + .map(|()| HeldLock::new(target.location.as_str(), ())) + } + async fn run( + &self, + _lock: &HeldLock, + _release: &str, + kind: RunKind, + ) -> Result { + assert_eq!(kind, RunKind::Migrate); + self.call("run"); + tokio::time::sleep(self.run_takes).await; + Ok(self.report.clone()) + } + async fn forget(&self, _lock: &HeldLock, _id: u32) -> Result<(), MigrationError> { + unreachable!("a server forgets nothing") + } + async fn release(&self, lock: HeldLock) { + self.call("release"); + drop(lock); + } + async fn status_notes(&self, _target: &Target) -> Result, MigrationError> { + self.call("notes"); + Ok(self.notes.clone()) + } +} + +fn behind() -> CatalogStatus { + CatalogStatus::Behind { + version: Some(1), + pending: MigrationId::ALL + .iter() + .skip(1) + .map(|id| Pending { + id: id.number(), + name: id.name(), + store: StoreKind::Catalog, + store_name: "db".to_owned(), + kind: Kind::Breaking, + }) + .collect(), + } +} + +fn current() -> CatalogStatus { + CatalogStatus::Current { + version: MigrationId::LATEST.number(), + } +} + +/// A catalog a newer binary migrated, ahead of this one by an additive +/// migration. +fn ahead() -> CatalogStatus { + CatalogStatus::AheadCompatible { + version: MigrationId::LATEST.number() + 1, + unknown: vec![(MigrationId::LATEST.number() + 1, "later".to_owned())], + } +} + +/// The statuses no server serves under either value of the policy, with +/// their exit codes, apart from `Uninitialized`, which a dev build serves. +fn unservable() -> Vec<(CatalogStatus, u8)> { + vec![ + ( + CatalogStatus::NeedsAttention { + items: vec!["migration 2: a collision".to_owned()], + }, + exit::ATTENTION, + ), + ( + CatalogStatus::Changed { + id: 1, + store_name: "db".to_owned(), + recorded: "a".to_owned(), + expected: "b".to_owned(), + }, + exit::ATTENTION, + ), + ( + CatalogStatus::WrittenByOlderRelease { + trace: "catalog_version is 0.0.4".to_owned(), + }, + exit::ATTENTION, + ), + ( + CatalogStatus::AheadIncompatible { + unknown: vec![(MigrationId::LATEST.number() + 1, "later".to_owned())], + }, + exit::AHEAD_INCOMPATIBLE, + ), + ] +} + +fn applied_report() -> RunReport { + RunReport { + from: Some(1), + to: Some(MigrationId::LATEST.number()), + applied: MigrationId::ALL + .iter() + .skip(1) + .map(|id| AppliedStep { + id: id.number(), + name: id.name(), + store_name: "db".to_owned(), + outcome: crate::migrations::Outcome::Applied, + notes: Vec::new(), + }) + .collect(), + notes: vec!["copied the database to db.pre-migration-1-to-4-x".to_owned()], + } +} + +const fn startup(apply: bool) -> Startup<'static> { + Startup { + apply, + creates_uninitialized: false, + release: "1.0.0-test", + lock_timeout: Duration::from_secs(1), + heartbeat: Duration::from_millis(50), + } +} + +/// A dev build's policy: the server creates a catalog in a store that is +/// not one yet. +const fn dev(apply: bool) -> Startup<'static> { + Startup { + creates_uninitialized: true, + ..startup(apply) + } +} + +/// Run the policy, returning its outcome and the lines it reported. +async fn prepare( + fake: &Fake, + startup: &Startup<'_>, +) -> (Result, Vec) { + let lines = Mutex::new(Vec::new()); + let result = prepare_to_serve(fake, &Target::at("db"), startup, &|line| { + lines.lock().unwrap().push(line.to_owned()); + }) + .await; + (result, lines.into_inner().unwrap()) +} + +#[tokio::test] +async fn refuse_stops_a_catalog_behind_with_exit_3_and_takes_no_lock() { + let fake = Fake::new(&[behind()]); + let (result, lines) = prepare(&fake, &startup(false)).await; + let error = result.expect_err("refused"); + assert_eq!(error, MigrationError::Status(behind())); + assert_eq!(error.exit_code(), exit::PENDING); + assert_eq!(fake.calls(), ["status"]); + assert_eq!(lines, [READING]); +} + +/// Under `apply` the run is `migrate --yes`'s: the status notes, the lock, +/// the status read again under it, the run, and the release. A line comes +/// before the first status read, which runs `detect`. +#[tokio::test] +async fn apply_migrates_a_catalog_behind_under_the_lock_and_releases_it() { + let fake = Fake::new(&[behind()]); + let (result, lines) = prepare(&fake, &startup(true)).await; + let prepared = result.expect("applied"); + assert_eq!(prepared.run, Some(applied_report())); + assert_eq!(prepared.warning, None); + assert_eq!( + fake.calls(), + ["status", "notes", "lock", "status", "run", "release"] + ); + let latest = MigrationId::LATEST.number(); + assert_eq!(lines[0], READING); + assert_eq!( + lines[1], + format!( + "the catalog is at migration 1 and this binary needs migration {latest}; applying \ + the pending migrations before the server starts" + ) + ); + assert!( + lines[2].starts_with("Pending (all breaking): 2 "), + "{lines:?}" + ); + assert_eq!( + lines[3], + "taking the migration lock, waiting up to 1 s for a server or another migration" + ); + assert_eq!(lines[4], "copied the database to db.pre-migration-1-to-4-x"); + assert_eq!(lines[5], "applied 2 resource_tag_condition_keys"); + assert_eq!( + lines.last().map(String::as_str), + Some(format!("the catalog is at migration {latest}").as_str()) + ); +} + +#[tokio::test] +async fn a_current_catalog_serves_with_no_lock_and_no_run() { + for apply in [false, true] { + let fake = Fake::new(&[current()]); + let (result, lines) = prepare(&fake, &startup(apply)).await; + assert_eq!(result, Ok(Prepared::default())); + assert_eq!(fake.calls(), ["status"]); + assert_eq!(lines, [READING]); + } +} + +#[tokio::test] +async fn a_catalog_ahead_by_additive_migrations_serves_with_a_warning() { + let ahead = ahead(); + for apply in [false, true] { + let fake = Fake::new(std::slice::from_ref(&ahead)); + let (result, _) = prepare(&fake, &startup(apply)).await; + let prepared = result.expect("served"); + assert_eq!(prepared.run, None); + let warning = prepared.warning.expect("a warning"); + assert!(warning.contains("additive"), "{warning}"); + assert_eq!(fake.calls(), ["status"]); + } +} + +/// No setting serves a catalog this binary cannot use: under `apply` every +/// status but `Behind` is refused as under `refuse`, before any lock. +#[tokio::test] +async fn apply_refuses_every_other_status_with_its_code_and_takes_no_lock() { + let mut cases = unservable(); + cases.push((CatalogStatus::Uninitialized, exit::ERROR)); + for (status, code) in cases { + for apply in [false, true] { + let fake = Fake::new(std::slice::from_ref(&status)); + let (result, lines) = prepare(&fake, &startup(apply)).await; + let error = result.expect_err("refused"); + assert_eq!(error, MigrationError::Status(status.clone())); + assert_eq!(error.exit_code(), code, "{status:?}"); + assert_eq!(fake.calls(), ["status"], "{status:?}"); + assert_eq!(lines, [READING]); + } + } +} + +/// A dev build serves a store that is not a catalog yet, which its server +/// creates; a production build refuses it with exit 1. +#[tokio::test] +async fn a_dev_build_leaves_an_uninitialized_store_to_the_server() { + let fake = Fake::new(&[CatalogStatus::Uninitialized]); + let (result, _) = prepare(&fake, &dev(false)).await; + assert_eq!(result, Ok(Prepared::default())); + assert_eq!(fake.calls(), ["status", "creates"]); +} + +/// A dev build serves only what any server serves, and a store its server +/// creates: every other status is refused with its code under both values, +/// and `Behind` under `refuse`, before any lock. `Behind` under `apply` is +/// migrated. +#[tokio::test] +async fn a_dev_build_refuses_every_status_its_server_cannot_serve() { + for (status, code) in unservable() { + for apply in [false, true] { + let fake = Fake::new(std::slice::from_ref(&status)); + let (result, _) = prepare(&fake, &dev(apply)).await; + let error = result.expect_err("refused"); + assert_eq!(error, MigrationError::Status(status.clone())); + assert_eq!(error.exit_code(), code, "{status:?}"); + assert_eq!(fake.calls(), ["status"], "{status:?}"); + } + } + let fake = Fake::new(&[behind()]); + let (result, _) = prepare(&fake, &dev(false)).await; + assert_eq!(result.expect_err("refused").exit_code(), exit::PENDING); + assert_eq!(fake.calls(), ["status"]); + + for status in [current(), ahead(), CatalogStatus::Uninitialized] { + for apply in [false, true] { + let fake = Fake::new(std::slice::from_ref(&status)); + let (result, _) = prepare(&fake, &dev(apply)).await; + assert_eq!(result.expect("served").run, None, "{status:?}"); + assert!(!fake.calls().contains(&"lock"), "{status:?}"); + } + } + let fake = Fake::new(&[behind()]); + let (result, _) = prepare(&fake, &dev(true)).await; + assert_eq!(result.expect("applied").run, Some(applied_report())); +} + +/// A store the backend's server would refuse, such as a SQLite file that +/// holds another program's tables, is refused before the server starts, +/// as `Uninitialized` with exit 1, in a dev build too. +#[tokio::test] +async fn a_dev_build_refuses_a_store_its_server_would_refuse() { + let mut fake = Fake::new(&[CatalogStatus::Uninitialized]); + fake.creates = false; + for apply in [false, true] { + let (result, _) = prepare(&fake, &dev(apply)).await; + let error = result.expect_err("refused"); + assert_eq!(error, MigrationError::Status(CatalogStatus::Uninitialized)); + assert_eq!(error.exit_code(), exit::ERROR); + } + assert!(!fake.calls().contains(&"lock"), "{:?}", fake.calls()); +} + +/// An in-memory store is created by the server that opens it: nothing is +/// read before. +#[tokio::test] +async fn an_in_process_store_is_not_read() { + let mut fake = Fake::new(&[behind()]); + fake.in_process = true; + let (result, lines) = prepare(&fake, &startup(true)).await; + assert_eq!(result, Ok(Prepared::default())); + assert!(fake.calls().is_empty(), "{:?}", fake.calls()); + assert!(lines.is_empty(), "{lines:?}"); +} + +/// A lock that stays held past the timeout stops the server with exit 6 +/// while the catalog is still behind. +#[tokio::test] +async fn a_lock_held_past_the_timeout_exits_6() { + let mut fake = Fake::new(&[behind()]); + fake.lock = Err(MigrationError::Locked( + "another migration holds it".to_owned(), + )); + let (result, lines) = prepare(&fake, &startup(true)).await; + let error = result.expect_err("locked"); + assert_eq!(error.exit_code(), exit::LOCKED); + assert_eq!(error.to_string(), "another migration holds it"); + // The status is read again after the wait, after a line saying so, and + // the backend ran nothing. + assert_eq!(fake.calls(), ["status", "notes", "lock", "status"]); + assert_eq!(lines.last().map(String::as_str), Some(super::READING_AGAIN)); +} + +/// Another process migrated the catalog while this one waited, and holds +/// what the lock waits for because it serves: the catalog needs nothing, +/// and the server starts as `serve` would. +#[tokio::test] +async fn a_catalog_migrated_by_another_process_during_the_wait_serves() { + let mut fake = Fake::new(&[behind(), current()]); + fake.lock = Err(MigrationError::Locked("a server serves it".to_owned())); + let (result, lines) = prepare(&fake, &startup(true)).await; + assert_eq!(result, Ok(Prepared::default())); + assert_eq!(fake.calls(), ["status", "notes", "lock", "status"]); + assert_eq!(lines.last().map(String::as_str), Some(MIGRATED_ELSEWHERE)); +} + +/// The same, with a newer binary that left the catalog ahead of this one +/// by additive migrations: it is served with the warning. +#[tokio::test] +async fn the_fallback_after_the_wait_serves_a_catalog_ahead_by_additive_migrations() { + let mut fake = Fake::new(&[behind(), ahead()]); + fake.lock = Err(MigrationError::Locked("a server serves it".to_owned())); + let (result, lines) = prepare(&fake, &startup(true)).await; + let prepared = result.expect("served"); + assert_eq!(prepared.run, None); + let warning = prepared.warning.expect("a warning"); + assert!(warning.contains("additive"), "{warning}"); + assert_eq!(fake.calls(), ["status", "notes", "lock", "status"]); + assert_eq!(lines.last().map(String::as_str), Some(MIGRATED_ELSEWHERE)); +} + +/// The status read under the lock finds the catalog migrated: the lock is +/// released and the catalog served without the backend's run, which on +/// PostgreSQL would make the pgvector attempt and open the runner's +/// sessions. +#[tokio::test] +async fn a_run_that_finds_the_catalog_migrated_under_the_lock_applies_nothing() { + let fake = Fake::new(&[behind(), current()]); + let (result, lines) = prepare(&fake, &startup(true)).await; + let prepared = result.expect("served"); + let latest = MigrationId::LATEST.number(); + assert_eq!( + prepared.run, + Some(RunReport { + from: Some(latest), + to: Some(latest), + ..RunReport::default() + }) + ); + assert_eq!(prepared.warning, None); + // The status read after the run looks for a catalog ahead by additive + // migrations. + assert_eq!( + fake.calls(), + ["status", "notes", "lock", "status", "release", "status"] + ); + assert_eq!(lines.last().map(String::as_str), Some(MIGRATED_ELSEWHERE)); +} + +/// A newer binary migrated the catalog while this one waited, ahead of it +/// by an additive migration: the run under the lock applies nothing, and +/// the status read after it gives the warning `migrate --yes` prints. +#[tokio::test] +async fn a_run_that_applied_nothing_warns_of_a_catalog_ahead_by_additive_migrations() { + let fake = Fake::new(&[behind(), ahead()]); + let (result, _) = prepare(&fake, &startup(true)).await; + let prepared = result.expect("served"); + assert!(prepared.run.expect("a run").applied.is_empty()); + let warning = prepared.warning.expect("a warning"); + assert!(warning.contains("additive"), "{warning}"); + assert_eq!( + fake.calls(), + ["status", "notes", "lock", "status", "release", "status"] + ); +} + +/// Under `apply` the server checks the status notes `migrate --yes` checks +/// before it takes the lock: a note that refuses runs stops it with exit 1 +/// and the same notes, naming the server's command, before any lock. A +/// note that does not refuse is printed as a progress line. +#[tokio::test] +async fn a_note_that_refuses_runs_stops_apply_before_the_lock() { + let note = StatusNote { + text: "the role does not own the tables".to_owned(), + refuses_runs: true, + }; + let mut fake = Fake::new(&[behind()]); + fake.notes = vec![note.clone()]; + let (result, lines) = prepare(&fake, &startup(true)).await; + let error = result.expect_err("refused"); + assert_eq!(error.exit_code(), exit::ERROR); + assert_eq!( + error.to_string().lines().collect::>(), + [ + "serve with --migrate or catalog_upgrade = \"apply\" refuses to apply migrations \ + while these notes hold:", + "Note: the role does not own the tables", + "Nothing was changed and no lock was taken.", + ] + ); + assert_eq!(fake.calls(), ["status", "notes", "status"]); + assert!( + !lines + .iter() + .any(|l| l.starts_with("taking the migration lock")), + "{lines:?}" + ); + + let mut fake = Fake::new(&[behind()]); + fake.notes = vec![StatusNote { + refuses_runs: false, + ..note + }]; + let (result, lines) = prepare(&fake, &startup(true)).await; + result.expect("applied"); + assert!( + lines + .iter() + .any(|l| l == "note: the role does not own the tables"), + "{lines:?}" + ); + assert!(fake.calls().contains(&"run"), "{:?}", fake.calls()); +} + +/// While the run goes on, a line says so every heartbeat, which is what +/// keeps the npm launcher waiting through a long migration. +#[tokio::test] +async fn a_long_run_reports_that_it_is_in_progress_every_heartbeat() { + let mut fake = Fake::new(&[behind()]); + fake.run_takes = Duration::from_millis(400); + let (result, lines) = prepare(&fake, &startup(true)).await; + result.expect("applied"); + let beats = lines + .iter() + .filter(|l| l.starts_with("in progress for ")) + .count(); + // Eight at the 50 ms heartbeat; fewer only when the host is loaded. + assert!(beats >= 4, "{beats} heartbeats: {lines:?}"); +} diff --git a/devtools/catalog_checks.py b/devtools/catalog_checks.py index b687def35..96e492227 100644 --- a/devtools/catalog_checks.py +++ b/devtools/catalog_checks.py @@ -2,7 +2,7 @@ # SPDX-License-Identifier: Apache-2.0 """What the catalog check scripts share: running a command with a time limit, checking its exit code, reporting each check, and starting and stopping a -server. +server, in the foreground or in daemon mode. devtools/check-sqlite-catalog-lock, check-sqlite-older-binary, check-postgres-catalog-lock, check-postgres-older-binary, @@ -13,9 +13,11 @@ command's output indented under a FAIL; `finish` prints the count of failed checks or `all checks passed` and returns the script's exit code. """ +import os import signal import subprocess import time +import tomllib failures = 0 @@ -52,6 +54,17 @@ def run(cmd: list[str], env: dict | None = None, timeout: float = 90, cwd: str | return done.returncode, done.stdout + done.stderr +def run_split(cmd: list[str], env: dict | None, timeout: float = 120) -> tuple[int, str, str]: + """Run `cmd` and return its exit code, stdout and stderr apart. A + command still running after `timeout` seconds is killed, and its code + is -1.""" + try: + done = subprocess.run(cmd, env=env, capture_output=True, text=True, timeout=timeout, check=False) + except subprocess.TimeoutExpired as e: + return -1, _text(e.stdout), f"still running after {timeout:g} s\n{_text(e.stderr)}" + return done.returncode, done.stdout, done.stderr + + def expect_exit( want: int, what: str, @@ -79,7 +92,11 @@ def healthy(url: str, proc: subprocess.Popen | None = None, seconds: float = 60) while time.monotonic() < deadline: if proc is not None and proc.poll() is not None: return False - probe = subprocess.run(["curl", "-sk", url], capture_output=True, text=True, check=False) + # A port that is bound but not accepting holds curl for its 300 s + # connect timeout, so each probe has its own limit. + probe = subprocess.run( + ["curl", "-sk", "--max-time", "2", url], capture_output=True, text=True, check=False + ) if "healthy" in probe.stdout: return True time.sleep(0.5) @@ -125,6 +142,57 @@ def stop(proc: subprocess.Popen) -> None: proc.wait() +def pid_file(config: str, env: dict, port: int) -> str: + """The PID file of a daemon started with `config`, `env` and + `--port port`: /extenddb-.pid, where run_dir is + EXTENDDB__SERVER__RUN_DIR, else `[server] run_dir` in `config`, else + ~/.extenddb/run, and ~ is env's HOME.""" + run_dir = env.get("EXTENDDB__SERVER__RUN_DIR") + if not run_dir: + try: + with open(config, "rb") as f: + run_dir = tomllib.load(f).get("server", {}).get("run_dir") + except (OSError, tomllib.TOMLDecodeError): + run_dir = None + run_dir = run_dir or "~/.extenddb/run" + if run_dir == "~" or run_dir.startswith("~/"): + run_dir = env.get("HOME", os.path.expanduser("~")) + run_dir[1:] + return os.path.join(run_dir, f"extenddb-{port}.pid") + + +def _command_line(pid: int) -> str: + try: + with open(f"/proc/{pid}/cmdline", "rb") as f: + return f.read().replace(b"\0", b" ").decode("utf-8", "replace") + except OSError: + done = subprocess.run(["ps", "-p", str(pid), "-o", "args="], capture_output=True, text=True, check=False) + return done.stdout + + +def kill_daemon(path: str, binary: str) -> None: + """Stop the daemon whose PID file is `path`, when one is running + `binary`: SIGTERM, then SIGKILL after 30 s. A daemon is not one of the + processes `start` started, and one left running would hold its port, + and on SQLite the database's lock, after the script ends.""" + try: + with open(path, encoding="utf-8") as f: + pid = int(f.read().split()[0]) + except (OSError, ValueError, IndexError): + return + # A PID file left behind can name a process that reused the PID. + command = _command_line(pid) + if binary not in command or " serve" not in command: + return + try: + os.kill(pid, signal.SIGTERM) + for _ in range(60): + time.sleep(0.5) + os.kill(pid, 0) + os.kill(pid, signal.SIGKILL) + except ProcessLookupError: + pass + + def finish() -> int: """Print the outcome of every check reported, and return the exit code.""" if failures: diff --git a/devtools/check-cassandra-catalog-lock b/devtools/check-cassandra-catalog-lock index d27061206..b04f53edf 100755 --- a/devtools/check-cassandra-catalog-lock +++ b/devtools/check-cassandra-catalog-lock @@ -32,6 +32,12 @@ with `init` and removes them at the end. and neither 2, which is not convergent, nor 3 and 4, which do not apply on Cassandra; migrate --forget 2 and the migrate --yes that applies 2 again run, and serve runs; +- the startup policy on a catalog behind this binary: serve exits 3 and + names --migrate, and in daemon mode the invoking process exits 3 with the + message on its stderr; while another session holds the migration lock, + serve --migrate waits for catalog_upgrade_lock_timeout, 3 s here and not + the 60 s default, and exits 6; once the lock is free, serve --migrate + applies the migration and serves; - with the node paused, a server that cannot renew its registration answers 503 within 40 s of the pause, before its row can expire (45 s after its last renewal, which came up to 5 s before the pause), then tries to @@ -49,7 +55,11 @@ import tempfile import time import tomllib -from catalog_checks import expect_exit, finish, healthy, report, run, start, stop, watch_lost_registration +from catalog_checks import ( + expect_exit, finish, healthy, kill_daemon, report, run, run_split, start, stop, + watch_lost_registration, +) +from catalog_checks import pid_file as pid_file_for ADMIN_USER = os.environ.get("CASSANDRA_ADMIN_USER", "cassandra") ADMIN_PASSWORD = os.environ.get("CASSANDRA_ADMIN_PASSWORD", "cassandra") @@ -165,6 +175,65 @@ def not_a_catalog(binary: str, env: dict, container: str, config: str, stem: str ) +def startup_policy( + binary: str, env: dict, container: str, config: str, keyspace: str, port: int, work: str, + servers: list, +) -> None: + """`serve`'s startup policy on a catalog behind this binary, in the + foreground and in daemon mode.""" + hint = "or start this server with --migrate" + serve = [binary, "serve", "--config", config, "--foreground", "--port", str(port)] + daemon = [binary, "serve", "--config", config, "--port", str(port)] + code, output = cqlsh( + container, f"CONSISTENCY QUORUM;\nDELETE FROM {keyspace}.extenddb_migrations WHERE id = 4;\n" + ) + report(code == 0, "the catalog is behind this binary by migration 4", output) + expect_exit(3, "serve on a catalog behind this binary", serve, env, contains=hint) + # The parent reads the status before it forks, so the code and the + # message reach the invoking shell. + code, out, err = run_split(daemon, env) + kill_daemon(pid_file_for(config, env, port), binary) + report( + code == 3 and hint in err, + f"exit {code}: serve in daemon mode on a catalog behind this binary, the message on stderr", + out + err, + ) + code, output = cqlsh( + container, + "CONSISTENCY QUORUM;\nSERIAL CONSISTENCY SERIAL;\n" + f"INSERT INTO {keyspace}.settings (key, value) VALUES ('migration_lock', " + "'held-by-check') IF NOT EXISTS USING TTL 300;\n", + ) + report(code == 0 and "True" in output, "the script holds the migration lock", output) + # Under 30 s tells the 3 s set here from the 60 s default. + started = time.monotonic() + expect_exit( + 6, + "serve --migrate while another session holds the migration lock", + serve + ["--migrate"], + dict(env, EXTENDDB__SERVER__CATALOG_UPGRADE_LOCK_TIMEOUT="3"), + contains="migration lock", + ) + waited = time.monotonic() - started + report(3 <= waited < 30, f"serve --migrate waited {waited:.1f} s for the lock, its 3 s timeout") + code, output = cqlsh( + container, + "CONSISTENCY QUORUM;\nSERIAL CONSISTENCY SERIAL;\n" + f"DELETE FROM {keyspace}.settings WHERE key = 'migration_lock' IF value = " + "'held-by-check';\n", + ) + report(code == 0 and "True" in output, "the script releases the lock", output) + log = os.path.join(work, "serve-migrate.log") + server = start(serve + ["--migrate"], env, log) + servers.append(server) + up = healthy(f"https://127.0.0.1:{port}/health", server) + stop(server) + with open(log, encoding="utf-8") as f: + report(up, "serve --migrate applies the pending migration and serves", f.read()) + expect_exit(0, "verify after serve --migrate", [binary, "verify", "--config", config], env, + contains="OK: Current") + + def main(binary: str, container: str, contact_point: str, port: int) -> int: binary = os.path.realpath(binary) stem = f"eddb_lock_{secrets.token_hex(4)}" @@ -279,6 +348,8 @@ def main(binary: str, container: str, contact_point: str, port: int) -> int: contains="Applied 2 resource_tag_condition_keys", ) + startup_policy(binary, env, container, config, keyspace, port, work, servers) + server = start(serve, env, log) servers.append(server) if not report(healthy(f"https://127.0.0.1:{port}/health", server), "serve once the lock is free"): @@ -318,6 +389,7 @@ def main(binary: str, container: str, contact_point: str, port: int) -> int: subprocess.run(["docker", "unpause", container], check=False) for server in servers: stop(server) + kill_daemon(pid_file_for(config, env, port), binary) cleanup(container, stem) shutil.rmtree(work, ignore_errors=True) return finish() diff --git a/devtools/check-mongodb-catalog-lock b/devtools/check-mongodb-catalog-lock index f13f764e6..c5b29caae 100755 --- a/devtools/check-mongodb-catalog-lock +++ b/devtools/check-mongodb-catalog-lock @@ -19,6 +19,12 @@ extenddb-check-lock-, published on 127.0.0.1 only: migrate --yes exits 6, and the preview still runs; - a server refuses a catalog behind this binary with 3, and the command it prints, run exactly as printed, applies what is missing; +- the startup policy on a catalog behind this binary: serve names + --migrate, and in daemon mode the invoking process exits 3 with the + message on its stderr; while another migration holds the lock, serve + --migrate waits for catalog_upgrade_lock_timeout, 3 s here and not the + 60 s default, and exits 6 naming the lock; once the lock is free, serve + --migrate applies the migration and serves; - a server killed with SIGKILL keeps migrate --yes waiting until its registration expires, at most 45 s after its last renewal; - a server whose database stops answering answers 503 within 40 s, before @@ -41,15 +47,7 @@ import tempfile import time from catalog_checks import ( - docker, - expect_exit, - finish, - healthy, - mongosh, - report, - start, - start_mongo, - stop, + docker, expect_exit, finish, healthy, kill_daemon, mongosh, report, run_split, start, start_mongo, stop, watch_lost_registration, ) @@ -69,6 +67,8 @@ def main(binary: str, mongo_port: int, api_port: int) -> int: container = f"extenddb-check-lock-{mongo_port}" work = tempfile.mkdtemp() servers = [] + # The run directory is EXTENDDB__SERVER__RUN_DIR below. + pid_file = os.path.join(work, "run", f"extenddb-{api_port}.pid") try: if not start_mongo(container, mongo_port): return finish() @@ -137,6 +137,36 @@ def main(binary: str, mongo_port: int, api_port: int) -> int: expect_exit(0, "the printed command, run as printed", [binary, *words[1:]], env) expect_exit(0, "verify after the printed command", verify, env) + # The startup policy on a catalog behind this binary. + mongosh(container, mongo_port, "db.getSiblingDB('extenddb_catalog').extenddb_migrations.deleteOne({_id: 4})") + expect_exit(3, "serve on a catalog behind this binary names --migrate", serve, env, timeout=60, + contains="or start this server with --migrate") + # The parent reads the status before it forks, so the code and the + # message reach the invoking shell. + daemon = [binary, "serve", "--config", "extenddb.toml", "--port", str(api_port)] + code, out, err = run_split(daemon, env) + kill_daemon(pid_file, binary) + report(code == 3 and "or start this server with --migrate" in err, + f"exit {code}: serve in daemon mode on a catalog behind this binary, the message on stderr", + out + err) + mongosh(container, mongo_port, "db.getSiblingDB('extenddb_catalog').settings.insertOne(" + "{_id: 'migration_lock', owner: 'check', expires_at: new Date(Date.now() + 120000)})") + # Under 30 s tells the 3 s set here from the 60 s default. + started = time.monotonic() + expect_exit(6, "serve --migrate while another migration holds the lock", serve + ["--migrate"], + dict(env, EXTENDDB__SERVER__CATALOG_UPGRADE_LOCK_TIMEOUT="3"), timeout=60, + contains="held the migration lock") + waited = time.monotonic() - started + report(3 <= waited < 30, f"serve --migrate waited {waited:.1f} s for the lock, its 3 s timeout") + mongosh(container, mongo_port, "db.getSiblingDB('extenddb_catalog').settings.deleteOne({_id: 'migration_lock'})") + server = start(serve + ["--migrate"], env, "serve-migrate.log") + servers.append(server) + up = healthy(url, server, 60) + stop(server) + with open("serve-migrate.log", encoding="utf-8") as f: + report(up, "serve --migrate applies the pending migration and serves", f.read()) + expect_exit(0, "verify after serve --migrate", verify, env, contains="OK: Current") + # A server killed without deleting its registration blocks # migrate --yes until the registration expires, 45 s after its last # renewal. @@ -161,7 +191,6 @@ def main(binary: str, mongo_port: int, api_port: int) -> int: # PID file. server = start(serve + ["--write-pid-file"], env, "serve-paused.log") servers.append(server) - pid_file = os.path.join(work, "run", f"extenddb-{api_port}.pid") if healthy(url, server, 60) and report(os.path.exists(pid_file), "the server wrote its PID file"): docker("pause", container) first_503, code, took = watch_lost_registration(server, url, 120) @@ -186,6 +215,7 @@ def main(binary: str, mongo_port: int, api_port: int) -> int: if server.poll() is None: server.send_signal(signal.SIGTERM) stop(server) + kill_daemon(pid_file, binary) docker("unpause", container) docker("rm", "-f", "-v", container) os.chdir("/") diff --git a/devtools/check-postgres-catalog-lock b/devtools/check-postgres-catalog-lock index 81a76f794..ece0b618c 100755 --- a/devtools/check-postgres-catalog-lock +++ b/devtools/check-postgres-catalog-lock @@ -20,6 +20,12 @@ given as `--data-db=`, so `init` has to create the database it names. exit 6, migrate --yes --lock-timeout 0 exits 6 within 10 s, and the preview exits 0; - once the lock is free, migrate --yes and serve run; +- the startup policy on a catalog behind this binary: serve exits 3 and + names --migrate, and in daemon mode the invoking process exits 3 with the + message on its stderr; while another session holds the migration lock, + serve --migrate waits for catalog_upgrade_lock_timeout, 3 s here and not + the 60 s default, and exits 6; once the lock is free, serve --migrate + applies the migration and serves; - a server whose registration session the database ends registers again on a new session and goes on serving, and migrate --yes exits 6 naming it; - a server whose registration session ends while a migration holds both @@ -45,7 +51,10 @@ import urllib.parse import psycopg2 -from catalog_checks import expect_exit, finish, healthy, report, run, start, stop +from catalog_checks import ( + expect_exit, finish, healthy, kill_daemon, report, run, run_split, start, stop, +) +from catalog_checks import pid_file as pid_file_for NAMESPACE = 0x0045_4442 # the advisory key namespace of crates/storage-postgres MIGRATION_KEY = 1 @@ -114,6 +123,68 @@ def just_renewed(admin_url: str, stem: str, seconds: float = 40) -> bool: conn.close() return False +MIGRATE_HINT = "or start this server with --migrate" + + +def behind(admin_url: str, stem: str) -> None: + """Delete the catalog's last ledger row, so the catalog is behind this + binary.""" + conn = psycopg2.connect(f"{admin_url.rstrip('/')}/{stem}_catalog") + conn.autocommit = True + with conn.cursor() as cur: + cur.execute( + "DELETE FROM extenddb_migrations WHERE id = (SELECT max(id) FROM extenddb_migrations)" + ) + conn.close() + + +def startup_policy( + binary: str, env: dict, config: str, port: int, admin_url: str, stem: str, servers: list +) -> None: + """`serve`'s startup policy on a catalog behind this binary, in the + foreground and in daemon mode.""" + serve = [binary, "serve", "--config", config, "--foreground", "--port", str(port)] + daemon = [binary, "serve", "--config", config, "--port", str(port)] + url = f"https://127.0.0.1:{port}/health" + behind(admin_url, stem) + expect_exit(3, "serve on a catalog behind this binary", serve, env, contains=MIGRATE_HINT) + # The parent reads the status before it forks, so the code and the + # message reach the invoking shell. + code, out, err = run_split(daemon, env) + kill_daemon(pid_file_for(config, env, port), binary) + report( + code == 3 and MIGRATE_HINT in err, + f"exit {code}: serve in daemon mode on a catalog behind this binary, the message on stderr", + out + err, + ) + # Another session holds the migration lock: serve --migrate waits for + # catalog_upgrade_lock_timeout, then exits 6. Under 30 s tells the 3 s + # set here from the 60 s default. + holder = psycopg2.connect(f"{admin_url.rstrip('/')}/{stem}_catalog") + with holder.cursor() as cur: + cur.execute("SELECT pg_advisory_xact_lock(%s, %s)", (NAMESPACE, MIGRATION_KEY)) + started = time.monotonic() + expect_exit( + 6, + "serve --migrate while another session holds the migration lock", + serve + ["--migrate"], + dict(env, EXTENDDB__SERVER__CATALOG_UPGRADE_LOCK_TIMEOUT="3"), + contains="another migrator holds the migration lock", + ) + waited = time.monotonic() - started + report(3 <= waited < 30, f"serve --migrate waited {waited:.1f} s for the lock, its 3 s timeout") + holder.rollback() + holder.close() + log = os.path.join(os.path.dirname(config), "serve-migrate.log") + server = start(serve + ["--migrate"], env, log) + servers.append(server) + up = healthy(url, server) + stop(server) + with open(log, encoding="utf-8") as f: + report(up, "serve --migrate applies the pending migration and serves", f.read()) + expect_exit(0, "verify after serve --migrate", [binary, "verify", "--config", config], env, + contains="OK: Current") + def main(binary: str, admin_url: str, port: int) -> int: binary = os.path.realpath(binary) @@ -197,6 +268,7 @@ def main(binary: str, admin_url: str, port: int) -> int: holder = None expect_exit(0, "migrate --yes once the lock is free", migrate + ["--yes", "--lock-timeout", "5"], env) + startup_policy(binary, env, config, port, admin_url, stem, servers) server = start(serve, env, log) servers.append(server) report(healthy(f"https://127.0.0.1:{port}/health", server), "serve once the lock is free") @@ -276,6 +348,7 @@ def main(binary: str, admin_url: str, port: int) -> int: finally: for server in servers: stop(server) + kill_daemon(pid_file_for(config, env, port), binary) if holder is not None: holder.close() cleanup(admin_url, stem) diff --git a/devtools/check-sqlite-catalog-lock b/devtools/check-sqlite-catalog-lock index 779a76def..4ce6255df 100755 --- a/devtools/check-sqlite-catalog-lock +++ b/devtools/check-sqlite-catalog-lock @@ -14,6 +14,19 @@ - once the database is free, migrate --yes and serve run; - on a catalog behind this binary, verify and the preview exit 3, and migrate --yes applies what is missing; +- the startup policy on a catalog behind this binary: serve exits 3 and + names --migrate, and in daemon mode the invoking process exits 3 with the + message on its stderr; serve --migrate, catalog_upgrade = "apply" in the + config file, EXTENDDB__SERVER__CATALOG_UPGRADE=apply and serve --migrate in + daemon mode each apply the migration and serve; serve --migrate on a + current catalog adds no ledger row and takes no copy; on a catalog that + needs a person it exits 5 and the database's content (read through its + WAL) is unchanged; while another process holds the database's lock it + waits for catalog_upgrade_lock_timeout, 3 s here and not the 60 s default, + and exits 6; +- two serve --migrate started together on a released catalog: the catalog + is migrated once, with one copy, exactly one of the two serves, and the + other finds nothing to apply or exits 6, and does not exit 1; - on a config whose database does not exist, migrate --yes exits 1, names extenddb init, and creates neither the database nor its directory. @@ -22,14 +35,29 @@ it so its TLS certificate is not written to the caller's home. The server binds 127.0.0.1 only. """ import fcntl +import glob import os import re import shutil import sqlite3 +import subprocess import sys import tempfile +import time -from catalog_checks import expect_exit, finish, healthy, report, run, start, stop +from catalog_checks import ( + expect_exit, finish, healthy, kill_daemon, pid_file, report, run, run_split, start, stop, +) + +REPO = os.path.dirname(os.path.dirname(os.path.realpath(__file__))) +RELEASED = os.path.join(REPO, "crates/storage-sqlite/tests/fixtures/released/dev-image-0.1.14.sql") +MIGRATE_HINT = "or start this server with --migrate" +NOTHING_TO_APPLY = "catalog migration: nothing to apply" +COLLIDING = ( + '{"Version":"2012-10-17","Statement":[{"Effect":"Deny","Action":"dynamodb:*",' + '"Resource":"*","Condition":{"StringEquals":{"aws:ResourceTag/env":"prod",' + '"dynamodb:ResourceTag/env":"dev"}}}]}' +) def with_path(config: str, database: str, out: str) -> None: @@ -40,14 +68,233 @@ def with_path(config: str, database: str, out: str) -> None: f.write(re.sub(r"(?m)^path = .*$", f'path = "{database}"', text)) +def with_server_line(config: str, line: str, out: str) -> None: + """Write `config` to `out` with `line` added to its [server] table.""" + with open(config, encoding="utf-8") as f: + text = f.read() + with open(out, "w", encoding="utf-8") as f: + f.write(re.sub(r"(?m)^\[server\]$", f"[server]\n{line}", text, count=1)) + os.chmod(out, 0o600) + + +def behind(database: str, first: int | None = None) -> None: + """Delete the catalog's last ledger row, or every row from id `first` + on, so the catalog is behind this binary.""" + # The copy a run takes before it migrates is named by the second it is + # taken in and never replaced, so two runs from the same migration need + # a second between them. + time.sleep(1.1) + conn = sqlite3.connect(database) + if first is None: + conn.execute( + "DELETE FROM extenddb_migrations WHERE id = (SELECT MAX(id) FROM extenddb_migrations)" + ) + else: + conn.execute("DELETE FROM extenddb_migrations WHERE id >= ?", (first,)) + conn.commit() + conn.close() + + +def ledger(database: str) -> list: + conn = sqlite3.connect(database) + rows = conn.execute("SELECT id, applied_at FROM extenddb_migrations ORDER BY id").fetchall() + conn.close() + return rows + + +def copies(database: str) -> list: + return sorted(glob.glob(f"{glob.escape(database)}.pre-migration-*")) + + +def content(database: str) -> list: + """The database's schema and rows as SQL. A connection reads through + the WAL, so a write a process left in `-wal` shows here, where the + bytes of the main file would not change.""" + conn = sqlite3.connect(database) + dump = list(conn.iterdump()) + conn.close() + return dump + + +def serves(cmd: list[str], env: dict | None, url: str, log: str, what: str, servers: list) -> bool: + """Start a foreground server, report whether it becomes healthy, and stop it.""" + server = start(cmd, env, log) + servers.append(server) + up = healthy(url, server, 60) + stop(server) + with open(log, encoding="utf-8") as f: + return report(up, what, f.read()) + + +def startup_policy(binary: str, database: str, port: int, env: dict, servers: list) -> None: + """`serve`'s startup policy on catalogs behind this binary and on one + that is current, in the foreground and in daemon mode.""" + url = f"https://127.0.0.1:{port}/health" + serve = [binary, "serve", "--config", "extenddb.toml", "--foreground", "--port", str(port)] + daemon = [binary, "serve", "--config", "extenddb.toml", "--port", str(port)] + daemon_pid = pid_file("extenddb.toml", env, port) + verify = [binary, "verify", "--config", "extenddb.toml"] + + behind(database) + expect_exit(3, "serve on a catalog behind this binary", serve, env, contains=MIGRATE_HINT) + # The parent reads the status before it forks, so the code and the + # message reach the invoking shell. + code, out, err = run_split(daemon, env) + kill_daemon(daemon_pid, binary) + report( + code == 3 and MIGRATE_HINT in err, + f"exit {code}: serve in daemon mode on a catalog behind this binary, the message on stderr", + out + err, + ) + serves(serve + ["--migrate"], env, url, "serve-migrate.log", + "serve --migrate applies the pending migration and serves", servers) + expect_exit(0, "verify after serve --migrate", verify, env, contains="OK: Current") + + behind(database) + with_server_line("extenddb.toml", 'catalog_upgrade = "apply"', "apply.toml") + serves([binary, "serve", "--config", "apply.toml", "--foreground", "--port", str(port)], env, url, + "serve-apply.log", 'catalog_upgrade = "apply" applies the pending migration and serves', + servers) + expect_exit(0, 'verify after catalog_upgrade = "apply"', verify, env, contains="OK: Current") + + behind(database) + serves(serve, dict(env, EXTENDDB__SERVER__CATALOG_UPGRADE="apply"), url, "serve-env.log", + "EXTENDDB__SERVER__CATALOG_UPGRADE=apply applies the pending migration and serves", servers) + expect_exit(0, "verify after EXTENDDB__SERVER__CATALOG_UPGRADE=apply", verify, env, + contains="OK: Current") + + # Daemon mode applies before it forks, reporting progress on stderr. + behind(database) + code, out, err = run_split(daemon + ["--migrate"], env) + up = code == 0 and healthy(url, None, 30) + expect_exit(0, "stop the daemon", [binary, "stop", "--config", "extenddb.toml", "--port", str(port)], env) + kill_daemon(daemon_pid, binary) + report( + up and "catalog migration: applied " in err, + f"exit {code}: serve --migrate in daemon mode applies before it forks and serves", + out + err, + ) + expect_exit(0, "verify after serve --migrate in daemon mode", verify, env, contains="OK: Current") + + # A current catalog: serve --migrate adds no ledger row and takes no + # copy. The server it starts writes to the database as any server does, + # so the rest of the content is not compared here. + rows, taken = ledger(database), copies(database) + serves(serve + ["--migrate"], env, url, "serve-current.log", + "serve --migrate on a current catalog serves", servers) + report(ledger(database) == rows and copies(database) == taken, + "serve --migrate on a current catalog added no ledger row and took no copy") + + # A catalog that needs a person: exit 5, and nothing written. + behind(database, first=2) + conn = sqlite3.connect(database) + account = conn.execute("SELECT account_id FROM accounts LIMIT 1").fetchone()[0] + conn.execute( + "INSERT INTO iam_users (account_id, user_name, user_arn) VALUES (?, 'collider', ?)", + (account, f"arn:aws:iam::{account}:user/collider"), + ) + conn.execute( + "INSERT INTO iam_policies (account_id, principal_type, principal_name, policy_name, " + "policy_document) VALUES (?, 'user', 'collider', 'colliding', ?)", + (account, COLLIDING), + ) + conn.commit() + conn.close() + before = content(database) + expect_exit(5, "serve --migrate on a catalog that needs a person", serve + ["--migrate"], env, + contains="needs a person") + report(content(database) == before and copies(database) == taken, + "serve --migrate on a catalog that needs a person left its content as it was and took no copy") + conn = sqlite3.connect(database) + conn.execute("DELETE FROM iam_policies WHERE policy_name = 'colliding'") + conn.execute("DELETE FROM iam_users WHERE user_name = 'collider'") + conn.commit() + conn.close() + expect_exit(0, "migrate --yes once the collision is gone", + [binary, "migrate", "--config", "extenddb.toml", "--yes", "--lock-timeout", "5"], env) + + # Another process holds the database's lock: serve --migrate waits for + # catalog_upgrade_lock_timeout, then exits 6. Under 30 s tells the 3 s + # set here from the 60 s default. + behind(database) + holder = open(os.path.realpath(database) + ".lock", "a+b") + fcntl.flock(holder, fcntl.LOCK_EX | fcntl.LOCK_NB) + started = time.monotonic() + expect_exit(6, "serve --migrate while another process holds the database's lock", + serve + ["--migrate"], dict(env, EXTENDDB__SERVER__CATALOG_UPGRADE_LOCK_TIMEOUT="3"), + contains="another extenddb process") + waited = time.monotonic() - started + report(3 <= waited < 30, f"serve --migrate waited {waited:.1f} s for the lock, its 3 s timeout") + fcntl.flock(holder, fcntl.LOCK_UN) + holder.close() + expect_exit(0, "migrate --yes once the lock is free", + [binary, "migrate", "--config", "extenddb.toml", "--yes", "--lock-timeout", "5"], env) + + +def two_servers(binary: str, work: str, port: int, env: dict, servers: list) -> None: + """Two serve --migrate started together on a released catalog: one of + them migrates it, with one copy, and exactly one of them serves. The + other finds nothing to apply, or exits 6 when it registers while the + first holds the database's lock. It does not exit 1, which is how a run + that collided with the first on the copy's name stops.""" + database = os.path.join(work, "released.sqlite") + conn = sqlite3.connect(database) + with open(RELEASED, encoding="utf-8") as f: + conn.executescript(f.read()) + conn.commit() + conn.close() + os.chmod(database, 0o600) + with_path("extenddb.toml", database, "released.toml") + lock_timeout_env = dict(env, EXTENDDB__SERVER__CATALOG_UPGRADE_LOCK_TIMEOUT="10") + ports = (port, port + 1) + procs = [] + for i, p in enumerate(ports): + cmd = [binary, "serve", "--config", "released.toml", "--foreground", "--migrate", "--port", str(p)] + proc = start(cmd, lock_timeout_env, f"two-{i}.log") + servers.append(proc) + procs.append(proc) + up = [healthy(f"https://127.0.0.1:{p}/health", proc, 60) for p, proc in zip(ports, procs)] + # The one that does not serve has exited, or exits once its wait for + # the lock ends; -1 when it is still running after that. + codes = [] + for serving, proc in zip(up, procs): + try: + codes.append(None if serving else proc.wait(timeout=30)) + except subprocess.TimeoutExpired: + codes.append(-1) + logs = [] + for i, proc in enumerate(procs): + stop(proc) + with open(f"two-{i}.log", encoding="utf-8") as f: + logs.append(f.read()) + both = "\n---\n".join(logs) + report(up.count(True) == 1, f"one of two serve --migrate serves ({up.count(True)} did)", both) + for p, serving, code, log in zip(ports, up, codes, logs): + if serving: + continue + found = NOTHING_TO_APPLY in log + report( + code not in (1, -1) and (found or code == 6), + f"the serve --migrate on port {p} that does not serve exited {code}, " + f"{'with' if found else 'without'} {NOTHING_TO_APPLY!r} in its log", + log, + ) + applied = [log for log in logs if "catalog migration: applied 1 baseline" in log] + report(len(applied) == 1, f"one of two serve --migrate applied the migrations ({len(applied)} did)", both) + report(len(copies(database)) == 1, "the released catalog was copied once", "\n".join(copies(database))) + expect_exit(0, "verify after two serve --migrate", [binary, "verify", "--config", "released.toml"], env, + contains="OK: Current") + + def main(binary: str, port: int) -> int: binary = os.path.realpath(binary) work = tempfile.mkdtemp() servers = [] holder = None + env = dict(os.environ, HOME=os.path.join(work, "home")) + daemon_pid = pid_file(os.path.join(work, "extenddb.toml"), env, port) try: os.chdir(work) - env = dict(os.environ, HOME=os.path.join(work, "home")) database = os.path.join(work, "db.sqlite") code, output = run( [binary, "init", "--backend", "sqlite", "--config", "extenddb.toml", @@ -107,6 +354,9 @@ def main(binary: str, port: int) -> int: expect_exit(3, "migrate preview on a catalog behind this binary", migrate) expect_exit(0, "migrate --yes applies what is missing", migrate + ["--yes", "--lock-timeout", "5"]) + startup_policy(binary, database, port, env, servers) + two_servers(binary, work, port, env, servers) + # A config whose database does not exist: migrate --yes refuses with # 1, names init, and creates neither the database nor its directory. missing = os.path.join(work, "missing") @@ -122,6 +372,7 @@ def main(binary: str, port: int) -> int: finally: for server in servers: stop(server) + kill_daemon(daemon_pid, binary) if holder is not None: holder.close() os.chdir("/") diff --git a/devtools/run-mongodb-tests b/devtools/run-mongodb-tests index f6e67930c..4031363c6 100755 --- a/devtools/run-mongodb-tests +++ b/devtools/run-mongodb-tests @@ -302,7 +302,8 @@ if [[ " ${RUN_TESTS_ARGS[*]} " == *" --rust"* ]]; then EXTENDDB_TEST_MONGODB_URI="mongodb://localhost:$MONGO_PORT/?replicaSet=rs0&directConnection=true" \ EXTENDDB_TEST_MONGODB_REQUIRED=1 \ cargo test -p extenddb-storage-mongodb --test migrations_fresh --test migrations_guards \ - --test migrations_holders --test migrations_locks --test migrations_released + --test migrations_holders --test migrations_locks --test migrations_released \ + --test migrations_startup echo "" fi echo "=== Running test suite via devtools/run-tests --backend mongodb ===" diff --git a/docker/README.md b/docker/README.md index 45b66d359..a050acb89 100644 --- a/docker/README.md +++ b/docker/README.md @@ -162,6 +162,18 @@ whether pgvector is available and goes on. A backup taken by a 0.1.x release can restore without its secondary indexes, so take a new backup of each table after the upgrade. +The serving container refuses a catalog behind its image: `serve` exits 3 and +prints the pending migrations, what to back up, and the command above. +`serve --migrate`, or `EXTENDDB__SERVER__CATALOG_UPGRADE=apply` in the serving +container's environment, makes the server apply the migrations itself before it +serves, through the same lock the Job takes. It exits 6 when the lock and the +running servers are not free within `[server] catalog_upgrade_lock_timeout` +seconds (60 by default), which bounds the whole wait, and when a migration holds +the lock as it registers. On Kubernetes keep the Job: the +[upgrade manual](../docs/manuals/07-upgrade-manual.md#deployment-recipes) gives +the reasons, and lists the +[exit codes of serve](../docs/manuals/07-upgrade-manual.md#exit-codes-of-serve). + ### Steady state Run only: diff --git a/docs/adr/0023-catalog-migrations.md b/docs/adr/0023-catalog-migrations.md index eeeb98a54..f92510981 100644 --- a/docs/adr/0023-catalog-migrations.md +++ b/docs/adr/0023-catalog-migrations.md @@ -279,11 +279,16 @@ that each backend implements, as follows. server that outlasted the timeout. `serve` reads the status before the backend creates its engine, because creating the engine writes to the catalog on several backends. It serves `Current` and `AheadCompatible`. - It refuses every other status with that status's exit code and a message - that lists the pending migrations with their kinds, says what to back up - on that backend, and gives the `migrate` command. A dev build applies an - `Uninitialized` or `Behind` catalog at startup through the same runner and - refuses the other statuses as a production build does. + What it does with a `Behind` catalog is its startup policy, + `[server] catalog_upgrade`. Under `refuse`, the default in a production + build, it exits 3 with a message that lists the pending migrations with + their kinds, says what to back up on that backend, and gives the + `migrate` command. Under `apply`, the default in a dev build, and for one + run under `serve --migrate` in any build, it applies them through the run + `migrate --yes` makes, under the migration lock, and then serves. Under + both values it refuses every other status with that status's exit code, + except that a dev build creates the catalog through the same runner in a + missing or empty database file. A binary serves a catalog ahead of it only when every id it does not know is additive, so a binary can be rolled back across additive migrations diff --git a/docs/manuals/01-architecture-guide.md b/docs/manuals/01-architecture-guide.md index 36ccd41c7..39916e713 100755 --- a/docs/manuals/01-architecture-guide.md +++ b/docs/manuals/01-architecture-guide.md @@ -180,23 +180,29 @@ extenddb daemonizes by default. Pass `serve --foreground` (alias `--no-daemon`) to stay attached, which is what container runtimes and process supervisors expect. -1. Parse CLI arguments and load configuration -2. Bind TCP socket (port conflicts reported before forking) -3. Fork to background via `daemonize`, writing a PID file to `run_dir` +1. Parse CLI arguments and load configuration. On a platform without daemon + mode, `serve` without `--foreground` stops here +2. Read the catalog's status, and under `[server] catalog_upgrade = "apply"` + or `serve --migrate` apply its pending migrations. A catalog the server + cannot serve stops it here, before the fork, with the status's exit code +3. Bind TCP socket. This comes after the catalog check, so the port accepts + no connection while the catalog migrates, and before the fork, so port + conflicts are reported to the invoking shell +4. Fork to background via `daemonize`, writing a PID file to `run_dir` (skipped entirely in `--foreground` mode, so no run directory is needed and the root filesystem can be read-only) -4. Initialize logging — syslog when daemonized, stderr in `--foreground` -5. Connect to the storage backend -6. Verify catalog version matches binary expectation -7. Start axum server on the pre-bound socket +5. Initialize logging: syslog when daemonized, stderr in `--foreground` +6. Connect to the storage backend +7. Verify catalog version matches binary expectation +8. Start axum server on the pre-bound socket Because `--foreground` writes no PID file, `extenddb stop` cannot signal a foreground server; stop it through whatever supervises it. `extenddb status` still reports it as running, with the PID shown as unknown. Pass `serve --foreground --write-pid-file` to write one anyway, which restores both commands at the cost of needing a writable `run_dir`. -8. Spawn background tasks (log level polling, throttling polling, GSI delay polling, stream cleanup, TTL expiry, metrics persistence) -9. On SIGTERM/SIGINT: drain connections (5s timeout), exit +9. Spawn background tasks (log level polling, throttling polling, GSI delay polling, stream cleanup, TTL expiry, metrics persistence) +10. On SIGTERM/SIGINT: drain connections (5s timeout), exit ## Catalog Model @@ -205,8 +211,8 @@ extenddb uses a dual-database architecture: - **Catalog database** (e.g., `extenddb_catalog`): Stores table metadata, account/user/group/role/policy definitions, access keys, settings, stream metadata, and metrics. Shared across all accounts. - **Data database** (e.g., `extenddb_catalog_data`): Stores user items, GSI/LSI data, and stream records. Each table gets its own PostgreSQL table. -On PostgreSQL, SQLite, Cassandra and MongoDB the catalog is versioned by its migration ledger, the `extenddb_migrations` table (on MongoDB a collection, in the catalog database and in the data database): the catalog version is the highest migration recorded in every store, and `serve` reads the catalog's status at startup and refuses a catalog that is behind it or carries a breaking migration it does not know. On Cassandra every account keyspace has a ledger beside the catalog keyspace's. -A server that refuses its catalog prints the status and the command that resolves it; for pending migrations that is `extenddb migrate --yes`. +On PostgreSQL, SQLite, Cassandra and MongoDB the catalog is versioned by its migration ledger, the `extenddb_migrations` table (on MongoDB a collection, in the catalog database and in the data database): the catalog version is the highest migration recorded in every store, and `serve` reads the catalog's status at startup and refuses a catalog that carries a breaking migration it does not know, and one that is behind it unless it runs under `[server] catalog_upgrade = "apply"` or `--migrate`. On Cassandra every account keyspace has a ledger beside the catalog keyspace's. +A server that refuses its catalog prints the status and the command that resolves it. A catalog behind the binary stops a server under `refuse`, the default in a production build; run `extenddb migrate --yes` to upgrade it, or start the server with `--migrate`. ## Pluggable Architecture diff --git a/docs/manuals/05-admin-guide.md b/docs/manuals/05-admin-guide.md index aa2b9b10b..4815c9762 100755 --- a/docs/manuals/05-admin-guide.md +++ b/docs/manuals/05-admin-guide.md @@ -91,6 +91,8 @@ These settings require a server restart to take effect. | `bind_addr` | `127.0.0.1` | Network interface to bind | | `port` | `18443` | HTTP port | | `region` | `us-east-1` | AWS region for ARN generation. Baked into every backup ARN the server issues, so it must stay within `[a-z0-9-]` (under a value outside that class `CreateBackup` is refused with a `ValidationException` naming `server.region`, since no backup ARN can be formed; backups taken before the upgrade under such a region keep an ARN `DescribeBackup`, `DeleteBackup`, and `RestoreTableFromBackup` refuse as "not valid"; the server logs a warning at startup). A backup ARN of the caller's account in another region is resolved in the server's region first, then as written; see the upgrade manual before changing this on a deployment with backups | +| `catalog_upgrade` | `refuse` (`apply` in a dev build) | What `serve` does with a catalog behind the binary: `refuse` exits 3 and names the pending migrations, and `apply` runs them at startup as `migrate --yes` does. `serve --migrate` sets `apply` for one run. Under both values `serve` refuses a catalog that is NeedsAttention, Changed, WrittenByOlderRelease, AheadIncompatible or Uninitialized, except that a dev build creates a catalog in a missing or empty database file; see the [upgrade manual](07-upgrade-manual.md#applying-migrations-at-startup) | +| `catalog_upgrade_lock_timeout` | `60` | Under `apply`, the seconds a `serve` run may spend in all its waits together (for the migration lock, for running servers, and on PostgreSQL for an earlier migrator's statements) before it exits 6; 0 makes one attempt; at most 86400 | #### [storage] @@ -941,7 +943,7 @@ Check that PostgreSQL is running and the connection string in `extenddb.toml` is **The catalog has pending migrations, or is ahead of the binary:** -On PostgreSQL, SQLite, Cassandra and MongoDB, `serve` reads the catalog's migration status before it opens the engine and refuses a catalog it cannot serve, printing the status and the command that resolves it. A catalog with pending migrations exits 3, for example `the catalog is at migration 4, and ExtendDB needs migration 5`, followed by the pending migrations and `extenddb migrate --config extenddb.toml --yes`. A catalog that a newer release migrated with a breaking migration exits 4 and names that release's migrations; upgrade the binary rather than the catalog. The [Upgrade Manual](07-upgrade-manual.md#the-catalog-status) lists every status with its exit code and the stop / migrate / start sequence. +On PostgreSQL, SQLite, Cassandra and MongoDB, `serve` reads the catalog's migration status before it opens the engine and refuses a catalog it cannot serve, printing the status and the command that resolves it. A catalog with pending migrations exits 3, for example `the catalog is at migration 4, and ExtendDB needs migration 5`, followed by the pending migrations, `extenddb migrate --config extenddb.toml --yes` and `or start this server with --migrate`. Under `[server] catalog_upgrade = "apply"`, or started with `--migrate`, the server applies the pending migrations and serves. A catalog that a newer release migrated with a breaking migration exits 4 and names that release's migrations; upgrade the binary rather than the catalog. The [Upgrade Manual](07-upgrade-manual.md#the-catalog-status) lists every status with its exit code and the stop / migrate / start sequence. ### Authentication Errors diff --git a/docs/manuals/07-upgrade-manual.md b/docs/manuals/07-upgrade-manual.md index fb24895ca..d86c86c65 100755 --- a/docs/manuals/07-upgrade-manual.md +++ b/docs/manuals/07-upgrade-manual.md @@ -4,7 +4,7 @@ ## Current Status -This release versions the PostgreSQL, SQLite, Cassandra and MongoDB catalogs by a migration ledger and carries catalog migrations 1 to 6, which `extenddb migrate --list` prints. **Every deployment created by a 0.1.x release runs `extenddb migrate --yes` once** before a server of this release starts on it: the server refuses a catalog with pending migrations. Migration 1 brings the catalog of every 0.1.x release to the v1.0 schema, migration 5 drops `continuous_backups`, a table and on MongoDB a collection (see [Catalog 0.0.5](#catalog-005)), and migration 6 adds the backup catalog index and the restore job records ([below](#migration-6-the-backup-catalog-index)). +This release versions the PostgreSQL, SQLite, Cassandra and MongoDB catalogs by a migration ledger and carries catalog migrations 1 to 6, which `extenddb migrate --list` prints. **Every deployment created by a 0.1.x release runs `extenddb migrate --yes` once** before a server of this release starts on it, or starts that server once with `extenddb serve --migrate` ([Applying migrations at startup](#applying-migrations-at-startup)): by default a server refuses a catalog with pending migrations. Migration 1 brings the catalog of every 0.1.x release to the v1.0 schema, migration 5 drops `continuous_backups`, a table and on MongoDB a collection (see [Catalog 0.0.5](#catalog-005)), and migration 6 adds the backup catalog index and the restore job records ([below](#migration-6-the-backup-catalog-index)). A backup that a 0.1.x release took can restore without its global and local secondary indexes: a SQLite backup taken by 0.1.14 records only the table's key schema and attribute definitions, and its restore creates the table with its items and no index. Take a new backup of each table after upgrading to v1.0, and keep the 0.1.x backups for their items only. @@ -27,7 +27,7 @@ Running `extenddb migrate --yes` on an up-to-date catalog changes nothing. | Status | Meaning | `serve` | `migrate` | `migrate --yes` | `verify` | |--------|---------|---------|-----------|-----------------|----------| | Current | Every migration this binary carries is recorded | serves | 0 | 0 | 0 | -| Behind | Migrations are pending | 3 | 3 | applies them, 0 | 3 | +| Behind | Migrations are pending | 3; applies them and serves under `catalog_upgrade = "apply"` or `--migrate` | 3 | applies them, 0 | 3 | | AheadCompatible | The catalog has migrations this binary does not know, all additive | serves, with a warning | 0 | 0 | 0 | | AheadIncompatible | The catalog has a migration this binary does not know that is breaking | 4 | 4 | 4 | 4 | | NeedsAttention | A pending migration found data that a person must fix; each item is named | 5 | 5 | 5 | 5 | @@ -35,7 +35,7 @@ Running `extenddb migrate --yes` on an up-to-date catalog changes nothing. | WrittenByOlderRelease | A 0.1.x release wrote to the catalog after it was migrated | 5 | 5 | 5; `--yes --reconverge` repairs it | 5 | | Uninitialized | Not a catalog; `extenddb init` creates one | 1 | 1 | 1 | 1 | -Exit status 6 means the migration lock, or a running server, was still held when `--lock-timeout` ran out; run the command again once it is free. Every refusal prints the command that resolves it. A dev build's `serve` applies a Behind or Uninitialized catalog at startup instead of refusing it. The `serve` codes are those of `serve --foreground`; in daemon mode `serve` exits 1 and writes the refusal to syslog. +Exit status 6 means the migration lock, or a running server, was still held when `--lock-timeout` ran out (for `serve`, `[server] catalog_upgrade_lock_timeout`), or that a migration held the lock when `serve` registered; run the command again once it is free. Every refusal prints the command that resolves it. A dev build's `serve` applies a Behind catalog at startup instead of refusing it, because `apply` is a dev build's default, and creates a catalog in a missing or empty database file. `serve` has the same codes in daemon mode, which is the default, and with `--foreground`: [Exit codes of serve](#exit-codes-of-serve) gives the one case where they differ. `verify` also checks the connection to the data database. When that check fails, `verify` exits 1 on a Behind catalog instead of 3, because `migrate --yes` cannot apply the pending migrations while the data database cannot be reached. It still exits 4 or 5 for the statuses that need a person. @@ -84,6 +84,8 @@ extenddb migrate --config extenddb.toml extenddb migrate --config extenddb.toml --yes ``` +The server can apply them instead: start it in step 6 with `extenddb serve --migrate --config extenddb.toml`, which applies the pending migrations as `migrate --yes` does before it serves, and run the `verify` of step 5 once it has started ([Applying migrations at startup](#applying-migrations-at-startup)). + `migrate` connects as the application role in the config file, which does all the schema work. On PostgreSQL that role must own every table, view and sequence in the public schema of both databases, and may create tables there, as it does after `init`. A catalog restored by another role (for example from a `pg_dump --no-owner` dump loaded by an admin) is not owned by it, and such a dump carries no grants, so the role cannot read the restored tables either: the preview, `verify` and `migrate --yes` exit 1 with the database's `permission denied for table settings` followed by the catalog database's note. The data database's name is a row of the catalog's `settings`, which the role cannot read, so the commands do not guess it and print a line saying so after the note. Run the catalog database's statements first, and the next run prints the data database's note, or pass `migrate --data-db ` to see both notes at once. When the role can read the tables but does not own them, the preview and `verify` print a note per database, and `migrate --yes` refuses with exit status 1 before it takes the lock, printing one note per line. Each note names the objects the role does not own, with their owners, and the statements to run in that database, numbered in the order they run, each with the role that runs it. For each owner a `DO` block, run by that owner or by a superuser, changes the owner of that owner's objects with `ALTER ... OWNER TO` and of nothing else. Where no superuser exists, as on a managed service, PostgreSQL lets an owner give an object only to a role it is a member of, and only when that role may create objects in the object's schema. Call the role that owns the restored objects ``. When it is not a superuser, the note first prints `GRANT "" TO ""`, run by an administrator that may grant the application role (on PostgreSQL 16, a role with `ADMIN OPTION` on it, which the role that created it holds; the application role cannot grant itself to ``). Then it prints `GRANT CREATE ON SCHEMA public TO ""` when the application role may not create tables there, run by the public schema's owner, then the `DO` blocks, and last `REVOKE "" FROM ""`, which takes back the membership the `DO` blocks needed. Skip that last statement if `` was already a member of ``. A superuser can run every statement as printed. The note does not use `REASSIGN OWNED BY`, which would also give the role the old owner's other databases and its objects in other schemas. A migration that still fails on a privilege (`must be owner of table ...`) stops, commits nothing in that database, and prints the same note. `--pg-user `, with the password in `EXTENDDB_PG_PASSWORD`, names an admin role for one step only, creating the pgvector extension in the data database, on that database's server; without it `migrate --yes` reports whether pgvector is available and goes on. `migrate` finds the data database through the name `init` recorded in the catalog's `settings` (`data_database_name`), and connects to it with the connection string `init` recorded beside it (`data_database_connection_string`), which the server connects with. A catalog that has no recorded name falls back to the catalog database name without its `_catalog` suffix. `--data-db ` overrides both and uses that database on the recorded connection string's server. When the two rows name different databases and `--data-db` is not given, `migrate`, `verify` and `serve` refuse with exit status 1 and name both; correct the row that is wrong. @@ -101,7 +103,7 @@ The two transactions that hold the keys, the server's registration and the migra On MongoDB, `migrate` connects with the connection string in the config file, which the server uses too. A user with the `readWrite` role on `extenddb_catalog` and on `extenddb_data` and no other role can run `init`, `migrate --yes`, `verify` and `serve`. `migrate --yes` takes the migration lock, a document in the catalog's `settings` collection, and then waits for the registration every running server keeps in the catalog's `extenddb_servers` collection, and after `--lock-timeout` exits 6 naming each server's host and pid. A server renews its registration every 5 s, and every second after a renewal failed, and deletes it when it stops, once every background worker has ended (it leaves it to expire when one could not be stopped); a server that was killed leaves it until it expires, at most 45 s after its last renewal. A server whose registration was deleted, or that has not renewed it for 30 s, for example because the primary stopped answering, answers new requests with `ServiceUnavailable` and registers again, as a PostgreSQL server does after its session ends (above): it serves again once it holds a new registration and the catalog's status is the one it started with, and it stops with exit 1 when a migration holds the lock, when the status changed, or when 30 s pass without a registration. The lock and the registrations expire by the clock of the replica set's primary, so keep the clocks of its members in sync with NTP. Migration 1 deletes the `resource_tag_migration` settings document in the transaction that records its catalog step, so a 0.1.14 server refuses the migrated catalog, and a run that fails before that transaction leaves the document in place. 0.1.12 and 0.1.13 servers read neither that document nor the catalog version, so they start on a migrated catalog and serve it: do not run them against it. To go back to a 0.1.x release, restore the backup taken before `migrate --yes`. A 0.1.x `migrate` on a migrated catalog reports a pending change, and its `--yes` writes the settings document back; this release's status then reports the catalog as written by an older release, and `migrate --yes --reconverge` repairs it. -On Cassandra, `migrate` connects as the role the config file names, which the server connects as too. `--cassandra-user ` connects as another role, with its password in `EXTENDDB_CASSANDRA_PASSWORD` or `--cassandra-pass`; a wrong password is reported as a connection timeout. Migration 1 adopts a 0.1.x catalog: it keeps every setting except the `resource_tag_migration` row, which it deletes, and records itself in a ledger in the catalog keyspace and in every account keyspace. On a cluster that runs `CassandraAuthorizer`, `init` grants the application role SELECT, MODIFY, CREATE and ALTER on the catalog keyspace, those four and DROP on the default account's keyspace, and CREATE ON ALL KEYSPACES, which CreateAccount needs to create a keyspace per account and which also lets the role create tables in every keyspace on the cluster; a run of `migrate --yes --cassandra-user ` that creates a missing account keyspace grants the application role the five permissions on it. A 0.1.x `init` granted the application role nothing, so a deployment created before 1.0 on such a cluster needs the statements below before `migrate`. `migrate --yes` takes the migration lock, a row in the catalog's `settings` table written by lightweight transactions, and then waits for the registration every running server of this release keeps in the catalog's `extenddb_servers` table, and after `--lock-timeout` exits 6 naming each server. A server renews its registration every 5 s, and every second after a renewal failed, and deletes it when it stops, once every background worker has ended (it leaves it to expire when one could not be stopped); a server that was killed leaves it until it expires, at most 45 s after its last renewal. A server tries its renewals for 30 s after the last one that succeeded, so it keeps serving through an outage of 25 to 30 s, depending on when the outage starts, for example while the only replica of the catalog restarts. After that, 30 to 35 s after its last successful renewal, it answers new requests with `ServiceUnavailable` and registers again, as a PostgreSQL server does after its session ends (above), and stops with exit 1 when a migration holds the lock, when the status changed, or when 30 s pass without a registration. A migration needs every replica of the catalog keyspace reachable: the lock is written at `SERIAL`, the registrations are read at `ALL`, and after each schema statement the runner waits until every live node reports the same schema version. `serve` refuses a catalog with pending migrations, exiting 3 under `--foreground` with the pending migrations and the `extenddb migrate --config --yes` command to run. A 0.1.x server refuses a migrated catalog. +On Cassandra, `migrate` connects as the role the config file names, which the server connects as too. `--cassandra-user ` connects as another role, with its password in `EXTENDDB_CASSANDRA_PASSWORD` or `--cassandra-pass`; a wrong password is reported as a connection timeout. Migration 1 adopts a 0.1.x catalog: it keeps every setting except the `resource_tag_migration` row, which it deletes, and records itself in a ledger in the catalog keyspace and in every account keyspace. On a cluster that runs `CassandraAuthorizer`, `init` grants the application role SELECT, MODIFY, CREATE and ALTER on the catalog keyspace, those four and DROP on the default account's keyspace, and CREATE ON ALL KEYSPACES, which CreateAccount needs to create a keyspace per account and which also lets the role create tables in every keyspace on the cluster; a run of `migrate --yes --cassandra-user ` that creates a missing account keyspace grants the application role the five permissions on it. A 0.1.x `init` granted the application role nothing, so a deployment created before 1.0 on such a cluster needs the statements below before `migrate`. `migrate --yes` takes the migration lock, a row in the catalog's `settings` table written by lightweight transactions, and then waits for the registration every running server of this release keeps in the catalog's `extenddb_servers` table, and after `--lock-timeout` exits 6 naming each server. A server renews its registration every 5 s, and every second after a renewal failed, and deletes it when it stops, once every background worker has ended (it leaves it to expire when one could not be stopped); a server that was killed leaves it until it expires, at most 45 s after its last renewal. A server tries its renewals for 30 s after the last one that succeeded, so it keeps serving through an outage of 25 to 30 s, depending on when the outage starts, for example while the only replica of the catalog restarts. After that, 30 to 35 s after its last successful renewal, it answers new requests with `ServiceUnavailable` and registers again, as a PostgreSQL server does after its session ends (above), and stops with exit 1 when a migration holds the lock, when the status changed, or when 30 s pass without a registration. A migration needs every replica of the catalog keyspace reachable: the lock is written at `SERIAL`, the registrations are read at `ALL`, and after each schema statement the runner waits until every live node reports the same schema version. `serve` refuses a catalog with pending migrations, exiting 3 with the pending migrations and the `extenddb migrate --config --yes` command to run, unless it runs under `catalog_upgrade = "apply"` or `--migrate`. A 0.1.x server refuses a migrated catalog. On a deployment created before 1.0 on a cluster that runs `CassandraAuthorizer`, this release's `migrate`, `verify` and `serve`, connected as the application role, fail with `Unauthorized ... has no SELECT permission on _catalog.accounts>` until the role holds its permissions. With every server stopped, run the statements below in `cqlsh` as a superuser; the application role cannot grant them to itself. `` and `` are `username` and `keyspace_prefix` under `[storage.cassandra]` in the config file. Each account has its own keyspace, so list the accounts first: @@ -179,6 +181,62 @@ This manual has no tested rollback for Cassandra. Before migrating, with every s Data written after the upgrade in schema shapes the previous version cannot represent is lost with the restore. +## Applying Migrations at Startup + +`serve` reads the catalog's status before it opens the catalog. The `[server]` key `catalog_upgrade` sets what it does with a catalog that is behind it: + +| Value | A catalog behind the binary | +|-------|-----------------------------| +| `refuse` | `serve` exits 3. The message lists the pending migrations, says which servers to stop and what to back up, gives the `migrate --yes` command, and ends with `or start this server with --migrate`. The default in a production build | +| `apply` | `serve` applies the pending migrations, then serves. The default in a dev build, which the dev image and the npm launcher run | + +`serve --migrate` sets `apply` for one run. `EXTENDDB__SERVER__CATALOG_UPGRADE` sets the key from the environment and overrides the config file, as it does for every key. `serve` refuses any other value with a configuration error. + +Under `apply`, `serve` migrates the catalog before it opens it, through the same run as `migrate --yes`: + +1. On PostgreSQL it reads the ownership notes before it takes the lock, as `migrate --yes` does. When the application role does not own every table, view and sequence in the public schema of both databases, `serve` exits 1 and prints the same notes, before any change. Step 4 of the [general upgrade procedure](#general-upgrade-procedure) describes the statements each note prints. +2. It takes the migration lock, which waits for another migration and for running servers to stop. On PostgreSQL the run also waits for any statement an earlier migrator left running. On every backend `[server] catalog_upgrade_lock_timeout` bounds the time the run spends in all of these waits together, 60 seconds by default and at most 86400 seconds. With a timeout of 0 the run tries each once. `EXTENDDB__SERVER__CATALOG_UPGRADE_LOCK_TIMEOUT` sets the timeout from the environment. +3. It reads the status again under the lock. When the catalog is Current or AheadCompatible by then, because another process migrated it while this one waited, the server releases the lock and starts, having written nothing. +4. It runs the `detect` step of every pending code migration. When one finds items, `serve` exits 5 and names them, having written nothing. +5. On SQLite it copies the database, as `migrate --yes` does. +6. It applies the migrations, releases the lock, registers as the catalog's server, and serves. + +When the wait reaches the timeout, the server reads the status once more. It starts on a catalog that another process migrated in the meantime, and exits 6 on any other. + +Two servers started together under `apply` migrate the catalog once. One of them applies the migrations. The other finds nothing to apply, after it takes the lock or, when the first server already serves, after its wait for that server's registration reaches the timeout. Either of the two can exit 6 when it registers while the other holds the lock, and comes back under its restart loop. On SQLite one of them serves and the other exits 6, because one server at a time can hold the database file. On PostgreSQL, Cassandra and MongoDB both can end up serving the catalog, and v1.0 supports one server per catalog ([Multi-Instance Considerations](11-deployment-guide.md#multi-instance-considerations)), so start one. + +While it migrates, `serve` prints progress lines on stderr, each starting with `catalog migration: `. Before the run they name the catalog's migration and the pending migrations, and say that the server is taking the lock. While the run goes on, a line every 5 seconds says how long it has taken so far. When the run ends, a line names each migration applied, and the last line names the migration the catalog is at. On PostgreSQL the lines that say what the run waits for go to stdout, without the prefix. The npm launcher's startup timeout of 15 seconds counts from the last of the prefixed lines. + +`serve` binds its port after the status read and the run, so the port accepts no connection while the catalog migrates. It still binds before it forks, so in daemon mode a port that is in use is reported to the invoking shell, after the migrations have been applied. On a platform without daemon mode, `serve` without `--foreground` fails before it reads the catalog. + +`apply` changes only what `serve` does with a Behind catalog. Under both values `serve` serves a Current or AheadCompatible catalog, and refuses every other status with its code from the [status table](#the-catalog-status) before it takes the lock: NeedsAttention, Changed and WrittenByOlderRelease with 5, AheadIncompatible with 4, and Uninitialized with 1, except that a dev build creates a catalog in a missing or empty database file. No setting or flag makes `serve` open a catalog in any of these states. + +`serve` connects with the credentials in the config file, as `migrate` does, and that role does all the schema work. It takes no admin role. When it applies migrations on PostgreSQL, it also tries to create the pgvector extension as the application role, as `migrate --yes` does without `--pg-user`, and prints the result. When the extension needs a role that may create it, the note names the command to run, `extenddb migrate --yes --pg-user `. + +On PostgreSQL, Cassandra and MongoDB, and on SQLite with a server older than 0.1.14, neither `serve --migrate` nor `migrate --yes` detects a running server of a release before 1.0. Stop every server before the upgrade from 0.1.x, as step 1 of the [general upgrade procedure](#general-upgrade-procedure) says. + +### Deployment Recipes + +- Single host: stop the server and take the backup the general upgrade procedure describes, then start the new binary with `extenddb serve --migrate --config extenddb.toml`, or run `extenddb migrate --config extenddb.toml --yes` before `serve`. +- Docker Compose: no change. The `extenddb-bootstrap` service runs `migrate --yes` before the server starts. +- Kubernetes: one replica, the Deployment strategy `Recreate`, and a migration Job applied in the same release as the new Deployment, as below. + +On Kubernetes the migration Job uses the serving Secret. It runs the preview first, which takes no lock, and `migrate --yes` only when the preview exits 3. Its container runs this as its `command`, with `CONFIG` set to the path of the config file: + +```sh +sh -c 'extenddb migrate --config "$CONFIG"; rc=$?; [ "$rc" -eq 3 ] || exit "$rc"; exec extenddb migrate --config "$CONFIG" --yes' +``` + +On a release with nothing to apply, the preview exits 0, so the Job succeeds even when a pod of the new release is already serving; `migrate --yes` would wait for that server and exit 6. When migrations are pending, the Job can start while the old pod is still in its termination grace period, because `migrate --yes` waits for that server's registration to end, for up to its `--lock-timeout`. That timeout, 60 seconds by default, has to be longer than the old pod takes to stop. A pod of the new release that starts before the Job finishes exits 3, and Kubernetes restarts it after its CrashLoopBackOff delay, which grows up to 5 minutes, so the new server can start up to 5 minutes after the Job ends. + +Do not run the Job as a Helm pre-upgrade hook. Helm runs that hook while the old pod still serves, so from 1.0 on its `migrate --yes` would exit 6 on every release that has a migration to apply, and on the upgrade from 0.1.x it would migrate the catalog while the old server still serves it, because `migrate --yes` cannot see a 0.1.x server on PostgreSQL, Cassandra or MongoDB. Run the Job rather than `serve --migrate` in the pod: the port accepts no connection while the catalog migrates, so a liveness probe fails and Kubernetes restarts the pod during a long migration. + +### Exit Codes of serve + +`serve` exits with the codes of the [status table](#the-catalog-status): 1 for an error, for a store that is not a catalog in a production build, and under `apply` on PostgreSQL when the ownership notes refuse the run; 3 for a catalog behind it under `refuse`; 4 and 5 as listed there; and 6 under `apply` when the lock or a running server outlasted `catalog_upgrade_lock_timeout`. Under both values a server also exits 6, without waiting, when a migration holds the lock as it registers. + +In daemon mode, the default, `serve` reads the status before it forks, and under `apply` it migrates before it forks too, so the invoking shell receives these codes and the message on stderr. After the fork the server registers, then reads the lock and the status again. A server that stops there, for example with 6 because a `migrate --yes` started between the two reads of the status, writes its message to syslog. The invoking shell then sees exit status 1 when the server stopped within about 3 seconds of the fork, and 0 when it stopped later. Under `--foreground` every code and message reaches the caller. + ## Version History The catalog versions below are those of the 0.1.x releases, and the commands, output and procedures in them are those of the 0.1.x binaries. This release upgrades the catalog of any 0.1.x release with the [general upgrade procedure](#general-upgrade-procedure): its migration 1 applies the changes catalogs 0.0.2 to 0.0.4 made, and its migration 5 the change catalog 0.0.5 made. @@ -250,7 +308,7 @@ The 0.1.x binaries named the rebuild in the preview, as `Pending: catalog 0.0.3 To roll back, stop the server, put the copied files back in place of the current ones (remove the current `-wal` and `-shm` first), and start the previous binary. -On SQLite, `extenddb serve` reads the catalog's migration ledger before it opens the database and refuses a catalog with pending migrations, exiting 3 under `--foreground` with each pending migration and the `extenddb migrate --config --yes` command to run (in daemon mode it exits 1 and writes the refusal to syslog); a dev build applies them at startup instead, taking the same copy. +On SQLite, `extenddb serve` reads the catalog's migration ledger before it opens the database and refuses a catalog with pending migrations, exiting 3 with each pending migration and the `extenddb migrate --config --yes` command to run; started with `--migrate`, and in a dev build by default, it applies them at startup instead, taking the same copy. The `extenddb migrate` command that `serve`, `migrate` and `verify` advise names the config file by its absolute path, quoted for a POSIX shell, so it can be pasted as printed. A relative `path` in `[storage.sqlite]`, such as the `extenddb.sqlite` that `init` writes, resolves against the directory a command runs in. So when the config file names the database by a relative `path`, or names none, the advised command starts with `EXTENDDB__STORAGE__SQLITE__PATH=`, and it reaches the same database from any directory. diff --git a/docs/manuals/08-install-linux.md b/docs/manuals/08-install-linux.md index 2b868522e..c61761d0f 100755 --- a/docs/manuals/08-install-linux.md +++ b/docs/manuals/08-install-linux.md @@ -177,7 +177,7 @@ version mismatch. Apply migrations: ```bash cargo build --release -./target/release/extenddb migrate --config extenddb.toml +./target/release/extenddb migrate --config extenddb.toml --yes ``` No data is lost; only the catalog schema is updated. @@ -197,7 +197,7 @@ No data is lost; only the catalog schema is updated. | Symptom | Fix | |--------------------------------------------------------|---------------------------------------------------------------------| | `connection refused` on port 18443 | Server not running. `./target/release/extenddb serve --config extenddb.toml`| -| `Catalog version X.Y.Z (binary expects A.B.C)` | `./target/release/extenddb migrate --config extenddb.toml` | +| `Catalog version X.Y.Z (binary expects A.B.C)` | `./target/release/extenddb migrate --config extenddb.toml --yes` | | `role "postgres" does not exist` | Use `--pg-user $(whoami)` if PG runs as your user | | `FATAL: Peer authentication failed` | Edit `pg_hba.conf` to allow `trust` or `md5` for local connections | | DROP DATABASE hangs after hard kill | Check for lingering backends: `ps -eo pid,command \| grep postgres` | diff --git a/docs/manuals/09-install-macos.md b/docs/manuals/09-install-macos.md index b1ca6de2d..1f574e3d5 100755 --- a/docs/manuals/09-install-macos.md +++ b/docs/manuals/09-install-macos.md @@ -155,7 +155,7 @@ version mismatch. Apply migrations: ```bash cargo build --release -./target/release/extenddb migrate --config extenddb.toml +./target/release/extenddb migrate --config extenddb.toml --yes ``` No data is lost; only the catalog schema is updated. @@ -184,7 +184,7 @@ No data is lost; only the catalog schema is updated. | Symptom | Fix | |--------------------------------------------------------|---------------------------------------------------------------------| | `connection refused` on port 18443 | Server not running. `./target/release/extenddb serve --config extenddb.toml`| -| `Catalog version X.Y.Z (binary expects A.B.C)` | `./target/release/extenddb migrate --config extenddb.toml` | +| `Catalog version X.Y.Z (binary expects A.B.C)` | `./target/release/extenddb migrate --config extenddb.toml --yes` | | `role "extenddb" does not exist` during init | Re-run with `--pg-user $(whoami)` | | DROP DATABASE hangs after hard kill | Check for lingering backends: `ps -eo pid,command \| grep postgres` | diff --git a/docs/manuals/11-deployment-guide.md b/docs/manuals/11-deployment-guide.md index bc0b59626..25207b2cf 100755 --- a/docs/manuals/11-deployment-guide.md +++ b/docs/manuals/11-deployment-guide.md @@ -139,6 +139,16 @@ exists, treat backend failures as something clients retry through. For Kubernetes, run `extenddb init` as an init container or a one-time Job, then deploy extenddb as a Deployment with the generated `extenddb.toml` mounted as a ConfigMap or Secret. +To upgrade on Kubernetes, run one replica with the Deployment strategy `Recreate`, and apply the new release's Deployment together with a migration Job that uses the serving Secret. The Job runs the preview first, which takes no lock, and `migrate --yes` only when the preview exits 3. Its container runs this as its `command`, with `CONFIG` set to the path of the config file: + +```sh +sh -c 'extenddb migrate --config "$CONFIG"; rc=$?; [ "$rc" -eq 3 ] || exit "$rc"; exec extenddb migrate --config "$CONFIG" --yes' +``` + +On a release with nothing to apply, the preview exits 0, so the Job succeeds even when a pod of the new release is already serving; `migrate --yes` would wait for that server and exit 6. When migrations are pending, the Job's `migrate --yes` waits for the old pod's registration to end while that pod finishes its termination grace period, for up to its `--lock-timeout`. That timeout, 60 seconds by default, has to be longer than the old pod takes to stop. A pod of the new release that starts before the Job finishes exits 3, and Kubernetes restarts it after its CrashLoopBackOff delay, which grows up to 5 minutes. + +Do not run the Job as a Helm pre-upgrade hook: Helm runs the hook while the old pod still serves, so from 1.0 on its `migrate --yes` would exit 6 on every release that has a migration to apply, and on the upgrade from 0.1.x it would migrate the catalog under the old server. Do not migrate in the pod either. Leave the `migrate` line out of the entrypoint above, and leave `catalog_upgrade` at its default, `refuse`, with no `EXTENDDB__SERVER__CATALOG_UPGRADE` in the pod's environment: the port accepts no connection while the server migrates, so a liveness probe would fail and restart the pod during a long migration. The [upgrade manual](07-upgrade-manual.md#deployment-recipes) describes the recipe and the upgrade from 0.1.x. + ### Air-Gapped ExtendDB requires no internet connectivity. All functionality is self-contained in the binary. Build on a connected host, transfer the binary and `extenddb.toml` to the air-gapped environment, and run. @@ -236,7 +246,7 @@ extenddb init \ ### Upgrades - [ ] Test upgrades in a staging environment first -- [ ] Run `extenddb migrate --config extenddb.toml` after binary upgrade +- [ ] Run `extenddb migrate --config extenddb.toml --yes` after the binary upgrade, or start the new server once with `extenddb serve --migrate --config extenddb.toml` ([Upgrade Manual](07-upgrade-manual.md#applying-migrations-at-startup)) - [ ] Verify catalog version matches: `extenddb verify --config extenddb.toml` ## systemd Service diff --git a/docs/troubleshooting.md b/docs/troubleshooting.md index 81fbbc7b3..5631764f6 100755 --- a/docs/troubleshooting.md +++ b/docs/troubleshooting.md @@ -69,7 +69,7 @@ See `docs/local-postgres-setup.md` for full setup instructions. **Cause:** The catalog's status, read from its migration ledgers, is not one this binary serves: exit 3 means migrations are pending, 4 that the catalog has a breaking migration this binary does not know, 5 that a person must act, and 6 that the migration lock or a running server outlasted `--lock-timeout`. The [status table](manuals/07-upgrade-manual.md#the-catalog-status) of the upgrade manual lists each status with its exit codes. -**Fix:** Run the command the message prints. For pending migrations that is `extenddb migrate --config extenddb.toml --yes`, after the backup the message names. +**Fix:** Run the command the message prints. For pending migrations that is `extenddb migrate --config extenddb.toml --yes`, after the backup the message names, or start the server with `--migrate`. For `serve`, exit 6 means that the wait outlasted `[server] catalog_upgrade_lock_timeout`, or that a migration held the lock when the server registered; start the server again once the lock is free. ### `the catalog at is not initialized; create it with 'extenddb init'` diff --git a/extenddb.sample.toml b/extenddb.sample.toml index 2443ccd3d..073c4a444 100755 --- a/extenddb.sample.toml +++ b/extenddb.sample.toml @@ -27,6 +27,10 @@ # port = 18443 # HTTP port # region = "us-east-1" # AWS region for ARN generation # run_dir = "~/.extenddb/run" # Directory for PID file (~ is expanded to $HOME) +# catalog_upgrade = "refuse" # A catalog behind this binary: "refuse" exits 3, "apply" runs its +# # migrations at startup ("apply" by default in a dev build) +# catalog_upgrade_lock_timeout = 60 # Under "apply", seconds `serve` waits in all for the migration +# # lock and running servers before it exits 6 (0: one attempt) [storage] # backend = "postgres" # Storage backend: "postgres" (default), "mongodb", or "sqlite". diff --git a/packaging/npm/README.md b/packaging/npm/README.md index cbacb5e8e..395dd3fff 100644 --- a/packaging/npm/README.md +++ b/packaging/npm/README.md @@ -50,12 +50,22 @@ calls in an async function (top-level `await` is ESM-only). | `dbPath` | data dir | SQLite file location (file mode only). | | `port` | ephemeral | Fixed port instead of an OS-assigned one. | | `binary` | bundled | Path to an `extenddb` binary, overriding the bundled one. | -| `startupTimeoutMs` | `15000` | How long to wait for the server to become healthy. | +| `startupTimeoutMs` | `15000` | How long to wait for the server to become healthy, counted from launch, or from the last catalog migration line the server prints if that is later. The server prints one every 5 s while it migrates, so a value under 5000 can give up during a migration. | +| `onProgress` | none | A function called with each catalog migration line the server prints on stderr while it starts. `extenddb start` writes these lines to its stderr. | The returned object carries `endpoint`, `port`, `credentials`, `region`, `storage`, and `stop()`, which shuts the server down and resolves when the process has exited. +When the server does not become healthy, `start()` stops it and rejects. If +the server exited first, the error's `exitCode` and `signal` are the server's, +and `extenddb start` exits with the server's exit code. + +In file mode, when an older release created the database, the server migrates +it before serving it. Before its first change it copies the database to +`.pre-migration--to--