diff --git a/beava-website/project/docs/concepts/streams/index.html b/beava-website/project/docs/concepts/streams/index.html index 0fdb61c0..c00552c7 100644 --- a/beava-website/project/docs/concepts/streams/index.html +++ b/beava-website/project/docs/concepts/streams/index.html @@ -115,7 +115,7 @@

Derived events

return ( checkout .filter(bv.col("amount") > 100) - .with_columns(bucket=bv.col("amount").cast(int) // 50) + .with_columns(bucket=bv.col("amount").cast("int") // 50) )`}

Push events to the parent (Click); beava routes matching records through the derivation chain and updates downstream tables for free. You never push to a derived event directly.

diff --git a/beava-website/project/docs/get-started/define-a-pipeline/index.html b/beava-website/project/docs/get-started/define-a-pipeline/index.html index 1d7c93ac..efb33801 100644 --- a/beava-website/project/docs/get-started/define-a-pipeline/index.html +++ b/beava-website/project/docs/get-started/define-a-pipeline/index.html @@ -125,21 +125,24 @@

What makes a good beava table?

Start with the feature your application actually needs. Add complexity only when the use case requires it.

Test your pipeline

-

Before you push real traffic at it, drive the pipeline with a fixture and assert what comes out. bv.test.fixture spins up an in-process server, lets you push synthetic events, and exposes the same get / batch_get API you use in production:

+

Before you push real traffic at it, drive the pipeline with a fixture and assert what comes out. bv.test.fixture is a pytest-shaped generator: yield from it inside your own @pytest.fixture and it spins up an in-process server, exposing the same get / batch_get API you use in production:

-{`import beava as bv - -def test_user_clicks_counts_within_window(): - with bv.test.fixture(Click, UserClicks) as f: - f.push("Click", {"user_id": "u_42"}) - f.push("Click", {"user_id": "u_42"}) - assert f.get("UserClicks", "u_42") == {"clicks_60s": 2} - - f.advance_time(seconds=120) - f.push("Click", {"user_id": "u_42"}) - assert f.get("UserClicks", "u_42") == {"clicks_60s": 1}`} +{`import pytest +import beava as bv +from beava.test import fixture + +@pytest.fixture +def app(): + # in-process server; reset_each=True gives every test a clean slate + yield from fixture(reset_each=True) + +def test_user_clicks_counts_within_window(app): + app.register(Click, UserClicks) + app.push("Click", {"user_id": "u_42"}) + app.push("Click", {"user_id": "u_42"}) + assert app.get("UserClicks", "u_42") == {"clicks_60s": 2}`} -

The fixture controls the clock with f.advance_time(...), so you can write deterministic tests for windowed aggregations without sleeping. Run with pytest; no extra config required.

+

The fixture yields a regular bv.App, so the test reads exactly like production code — register, push, get. Run with pytest; no extra config required.

Go deeper

Pipelines are written in Python. The engineer who understands the feature can also ship it; the runtime is a single binary that you talk to over HTTP.

diff --git a/beava-website/project/field-guide-ch1.html b/beava-website/project/field-guide-ch1.html index 38959f79..cabe4965 100644 --- a/beava-website/project/field-guide-ch1.html +++ b/beava-website/project/field-guide-ch1.html @@ -130,13 +130,13 @@

Try it — 3 curl commands

 # 1. Register the pipeline{'\n'}
-curl -X POST localhost:8080/pipelines -d @pipeline.py{'\n'}{'\n'}
+curl -X POST localhost:8080/register -d @pipeline.json{'\n'}{'\n'}
 # 2. Send a watch{'\n'}
-curl -X POST localhost:8080/events/Watch \
+curl -X POST localhost:8080/push \
{' '}-H 'content-type: application/json' \
-{' '}-d {`'{"user_id":"u1","video_id":"v_abc","watch_seconds":42}'`}{'\n'}{'\n'} +{' '}-d {`'{"event":"Watch","data":{"user_id":"u1","video_id":"v_abc","watch_seconds":42}}'`}{'\n'}{'\n'} # 3. Ask what this user cares about in the last hour{'\n'} -curl localhost:8080/features/UserTagAffinity?user_id=u1{'\n'} +curl localhost:8080/get/UserTagAffinity/u1{'\n'} {`# => [{"tag":"woodworking","weight_1h":42.0,...}, ...]`}
diff --git a/beava-website/project/field-guide-ch2.html b/beava-website/project/field-guide-ch2.html index e87a5844..ba91fc6a 100644 --- a/beava-website/project/field-guide-ch2.html +++ b/beava-website/project/field-guide-ch2.html @@ -134,13 +134,13 @@

Try it — 3 curl commands

 # 1. Register the pipeline{'\n'}
-curl -X POST localhost:8080/pipelines -d @pipeline.py{'\n'}{'\n'}
+curl -X POST localhost:8080/register -d @pipeline.json{'\n'}{'\n'}
 # 2. Send a watch{'\n'}
-curl -X POST localhost:8080/events/Watch \
+curl -X POST localhost:8080/push \
{' '}-H 'content-type: application/json' \
-{' '}-d {`'{"user_id":"u1","video_id":"v_abc","watch_seconds":42}'`}{'\n'}{'\n'} +{' '}-d {`'{"event":"Watch","data":{"user_id":"u1","video_id":"v_abc","watch_seconds":42}}'`}{'\n'}{'\n'} # 3. Ask what this user cares about in the last hour{'\n'} -curl localhost:8080/features/UserTagAffinity?user_id=u1{'\n'} +curl localhost:8080/get/UserTagAffinity/u1{'\n'} {`# => [{"tag":"woodworking","weight_1h":42.0,...}, ...]`}
diff --git a/beava-website/project/guide/chapter-1/index.html b/beava-website/project/guide/chapter-1/index.html index a2b380c2..fb3f2f5c 100644 --- a/beava-website/project/guide/chapter-1/index.html +++ b/beava-website/project/guide/chapter-1/index.html @@ -473,9 +473,12 @@

-{'# curl (recommended) — fetches the platform wheel from latest GH Release\n'} +{'# pip (recommended) — fetches the platform wheel + bundled server binary\n'} {'$ pip install beava\n'} {'\n'} +{'# brew (macOS / Linux) — server binary on PATH the Homebrew way\n'} +{'$ brew install beava-dev/beava/beava\n'} +{'\n'} {'# docker (zero deps on host — :edge tag rebuilt from main on every push)\n'} {'$ docker run -p 8080:8080 -p 8081:8081 beavadev/beava:edge\n'} {'\n'} @@ -690,14 +693,15 @@

- // with the user_ids visible on screen, gets back the metrics, renders. + // actual rows in state. Teaches: your app calls POST /batch_get with + // {requests:[{table,key},...]}, gets back {results:[...]}, renders. const QueryPanel = ({ table, userIds, rowsList, metricKeys, empty, onFirstRun, autoRefreshMs }) => { // Show all visible users (up to 6 to keep the payload readable). const ids = userIds.slice(0, 6); - const curl = `curl -X POST https://your-beava/batch/${table} \\ + const reqBody = JSON.stringify({ requests: ids.map(k => ({ table, key: k })) }); + const curl = `curl -X POST https://your-beava/batch_get \\ -H 'Content-Type: application/json' \\ - -d '${JSON.stringify(ids)}'`; + -d '${reqBody}'`; // User-triggered query: the response only appears after "Run query" // is clicked. Once clicked, auto-refresh kicks in so the snapshot @@ -720,20 +724,23 @@

{ const rowByUid = new Map(rowsRef.current); - const obj = {}; + const results = []; for (const uid of idsRef.current) { const r = rowByUid.get(uid); - if (!r) { obj[uid] = null; continue; } + // Server returns a flat feature map per result, in request order + // (no table/entity_id/key wrapping). const o = {}; - for (const k of metricKeys) { - if (k === 'views_total') o.views_total = r.views_total; - else if (k === 'views_24h') o.views_24h = r.views_24h; - else if (k === 'distinct_cats_7d') o.distinct_cats_7d = r.cats.size; - else if (k === 'last_seen') o.last_seen = new Date(r.lastTsMs).toISOString().replace(/\.\d{3}Z$/, 'Z'); + if (r) { + for (const k of metricKeys) { + if (k === 'views_total') o.views_total = r.views_total; + else if (k === 'views_24h') o.views_24h = r.views_24h; + else if (k === 'distinct_cats_7d') o.distinct_cats_7d = r.cats.size; + else if (k === 'last_seen') o.last_seen = new Date(r.lastTsMs).toISOString().replace(/\.\d{3}Z$/, 'Z'); + } } - obj[uid] = o; + results.push(o); } - return JSON.stringify(obj, null, 2); + return JSON.stringify({ results }, null, 2); }, [metricKeys]); const doFetch = React.useCallback((opts = {}) => { @@ -777,7 +784,7 @@

- ↓ how your app reads it: POST /batch/{table} + ↓ how your app reads it: POST /batch_get
{state === 'done' && latency != null && ( @@ -806,9 +813,9 @@

1. request — copy-paste this into your terminal

-                  $ curl -X POST https://your-beava/batch/{table} \{'\n'}
+                  $ curl -X POST https://your-beava/batch_get \{'\n'}
                   {'    '}-H 'Content-Type: application/json' \{'\n'}
-                  {'    '}-d '{JSON.stringify(ids)}'
+                  {'    '}-d '{reqBody}'
                 
diff --git a/beava-website/project/index.html b/beava-website/project/index.html index da333d64..214f4e68 100644 --- a/beava-website/project/index.html +++ b/beava-website/project/index.html @@ -320,7 +320,7 @@ }; const FeedRow = ({ row, now, columnWidths }) => ( -
top_issue_30m = bv.top_k("topic", k=1, window="30m",{'\n'} {' '}where=(bv.col("event") == "api_error") | (bv.col("event") == "docs_view")),{'\n'} {' '}){'\n\n'} - bv.App("0.0.0.0:6400").register(CustomerEvent, CustomerState).serve() + bv.App("http://localhost:8080").register(CustomerEvent, CustomerState) ); @@ -1024,7 +1025,7 @@ {' '}return e.group_by("shopper_id").agg({'\n'} {' '}view_price_30m = bv.mean("price", window="30m", where=bv.col("event") == "view"),{'\n'} {' '}){'\n\n'} - bv.App("0.0.0.0:6400").register(CommerceEvent, SkuMomentum, ShopperIntent).serve() + bv.App("http://localhost:8080").register(CommerceEvent, SkuMomentum, ShopperIntent) ); @@ -1050,7 +1051,7 @@ {' '}return e.group_by("zone_id").agg({'\n'} {' '}jobs_5m = bv.count(window="5m", where=bv.col("event") == "job_created"),{'\n'} {' '}){'\n\n'} - bv.App("0.0.0.0:6400").register(OpsEvent, VendorHealth, ZonePressure).serve() + bv.App("http://localhost:8080").register(OpsEvent, VendorHealth, ZonePressure) ); @@ -1339,7 +1340,8 @@ to { opacity: 1; transform: translateY(0); } } @media (max-width: 920px) { - .beava-pipelines-grid { grid-template-columns: 1fr !important; } + .beava-pipelines-grid { grid-template-columns: minmax(0, 1fr) !important; } + .beava-pipelines-grid > * { min-width: 0 !important; } } `} diff --git a/beava-website/project/js/_shared/SiteFooter.jsx b/beava-website/project/js/_shared/SiteFooter.jsx index 826a5d3f..2932beba 100644 --- a/beava-website/project/js/_shared/SiteFooter.jsx +++ b/beava-website/project/js/_shared/SiteFooter.jsx @@ -55,12 +55,12 @@ const SiteFooter = ({ maxWidth = 1200 }) => ( {SITE_FOOTER_COLS.map(col => (
{col.title}
-
    +
      {col.links.map(l => (
    • + style={{ fontFamily: 'var(--font-sans)', fontSize: 14, color: 'var(--fg2)', textDecoration: 'none', display: 'inline-block', padding: '5px 0' }}> {l.label}
    • diff --git a/beava-website/project/sdk/python/index.html b/beava-website/project/sdk/python/index.html index e9d750cb..45f330c2 100644 --- a/beava-website/project/sdk/python/index.html +++ b/beava-website/project/sdk/python/index.html @@ -140,11 +140,12 @@

      Pick a path

      01 Install beava

      -

      pip install beava drops a platform wheel from PyPI. The wheel ships the SDK and the Rust server binary together (~4 MB, polars / ruff / uv pattern). If you'd rather run the server in a container, Docker is the alternative.

      +

      Three ways in, pick whichever fits your stack. pip install beava drops a platform wheel from PyPI that ships the SDK and the Rust server binary together (~4 MB, polars / ruff / uv pattern). brew install puts the server binary on your PATH the Homebrew way. docker run hands you a container on :8080 with a persistent volume.

      +
      @@ -164,6 +165,22 @@

      01 Install beava

      The wheel comes from PyPI. The bundled beava binary lands in your Python user-scripts dir (~/.local/bin/beava on Linux, ~/Library/Python/<ver>/bin/beava on macOS), so embed mode (bv.App() with no URL) finds it without extra setup. Pin a specific version with pip install beava==0.0.0. Add --memory-only to skip the WAL entirely.

      +
      +
      +
      + terminal + +
      +
      brew install beava-dev/beava/beava
      +
      +# server binary on PATH; `beava` is ready to run
      +beava --data-dir ./.beava/
      +# → HTTP listen   : 127.0.0.1:8080
      +# → TCP listen    : 127.0.0.1:8081 (enabled=true)
      +
      +

      The formula installs the beava server binary into your Homebrew prefix (/opt/homebrew/bin/beava on Apple Silicon, /usr/local/bin/beava on Intel). Roll forward with brew upgrade beava. The Python SDK still comes from pip install beava; install both if you want embed mode and the client in the same env.

      +
      +
      diff --git a/crates/beava-core/src/agg_compile.rs b/crates/beava-core/src/agg_compile.rs index d551678e..3ea0a5a2 100644 --- a/crates/beava-core/src/agg_compile.rs +++ b/crates/beava-core/src/agg_compile.rs @@ -553,13 +553,28 @@ pub fn compile_aggregations_from_nodes( // Validate group keys. for (key_idx, key) in keys.iter().enumerate() { - if !upstream_schema.fields.contains_key(key.as_str()) { - errors.push(ValidationError { - code: ErrorCode::AggregationUnknownField, - path: format!("nodes[{node_idx}].ops[{op_idx}].group_by[{key_idx}]"), - reason: format!("group_by key '{key}' does not exist in upstream schema"), - }); - deriv_errors = true; + match upstream_schema.fields.get(key.as_str()) { + None => { + errors.push(ValidationError { + code: ErrorCode::AggregationUnknownField, + path: format!("nodes[{node_idx}].ops[{op_idx}].group_by[{key_idx}]"), + reason: format!( + "group_by key '{key}' does not exist in upstream schema" + ), + }); + deriv_errors = true; + } + Some(crate::schema::FieldType::F64) => { + errors.push(ValidationError { + code: ErrorCode::AggregationUnknownField, + path: format!("nodes[{node_idx}].ops[{op_idx}].group_by[{key_idx}]"), + reason: format!( + "group_by key '{key}' cannot be float-typed; cast to str/int/bool first" + ), + }); + deriv_errors = true; + } + Some(_) => {} } } @@ -1513,6 +1528,33 @@ mod tests { ); } + #[test] + fn rule11_rejects_float_group_key() { + let nodes = vec![ + event_node_with_fields( + "Txn", + &[("user_id", FieldType::Str), ("amount", FieldType::F64)], + ), + group_by_derivation( + "AmountStats", + "Txn", + vec!["amount"], + serde_json::json!({ + "cnt": {"op": "count", "params": {}} + }), + ), + ]; + let (_, errors) = compile_aggregations_from_nodes(&nodes, &empty_registry(), &[]); + assert!( + errors.iter().any(|e| { + e.code == ErrorCode::AggregationUnknownField + && e.path.contains("group_by") + && e.reason.contains("cannot be float-typed") + }), + "expected float group_by rejection, got: {errors:#?}" + ); + } + #[test] fn rule11_rejects_unknown_op_field() { let nodes = vec![ diff --git a/crates/beava-core/src/agg_state_table.rs b/crates/beava-core/src/agg_state_table.rs index a75673c0..2af0f139 100644 --- a/crates/beava-core/src/agg_state_table.rs +++ b/crates/beava-core/src/agg_state_table.rs @@ -51,6 +51,7 @@ use std::hash::{Hash, Hasher}; use crate::agg_descriptor::AggregationDescriptor; use crate::agg_op::AggOp; use crate::row::{Row, Value}; +use crate::schema::FieldType; use compact_str::CompactString; use fxhash::FxBuildHasher; use hashbrown::HashMap; @@ -429,7 +430,8 @@ pub fn has_entries_for_name( /// /// **Snapshot serialization (back-compat):** `iter_sorted` reconstructs /// canonical `EntityKey` from the three maps, preserving the serialized -/// snapshot format. `insert_from_entity_key` is the recovery-path inverse. +/// snapshot format. `insert_from_entity_key` is the recovery-path inverse +/// and restores each key into the same runtime sub-map the apply path uses. /// /// **Query path:** `query_feature` takes an `EntityKey` (built by the query /// parser from URL/JSON parameters) and routes through the appropriate map. @@ -539,9 +541,70 @@ impl AggStateTable { } /// Recovery path: insert a `(EntityKey, Vec)` pair loaded from a - /// snapshot. Routes via the `multi` sub-map (EntityKey is always canonical - /// Value::Str pairs in the snapshot format). + /// snapshot. Routes through the same sub-map selection as the apply hot + /// path, so post-snapshot WAL replay updates the restored row instead of + /// creating a duplicate in a different storage shape. pub fn insert_from_entity_key(&mut self, key: EntityKey, ops: Vec) { + self.insert_from_entity_key_with_types(key, ops, None); + } + + /// Recovery path with descriptor field types available. Older snapshots + /// serialized single numeric/bool/datetime keys as `Value::Str`; use the + /// source schema to coerce those legacy keys back into the hot-path shape. + pub fn insert_from_entity_key_with_types( + &mut self, + key: EntityKey, + ops: Vec, + group_key_types: Option<&[FieldType]>, + ) { + if self.group_keys.is_empty() { + self.group_keys = key.0.iter().map(|(name, _)| name.to_string()).collect(); + } + + if key.0.len() == 1 { + let (_, value) = &key.0[0]; + let value = match (value, group_key_types.and_then(|types| types.first())) { + (Value::Str(s), Some(FieldType::I64)) => s.parse::().ok().map(Value::I64), + (Value::Str(s), Some(FieldType::F64)) => s.parse::().ok().map(Value::F64), + (Value::Str(s), Some(FieldType::Bool)) => s.parse::().ok().map(Value::Bool), + (Value::Str(s), Some(FieldType::Datetime)) => { + s.parse::().ok().map(Value::Datetime) + } + _ => None, + } + .unwrap_or_else(|| value.clone()); + + match value { + Value::Str(s) => { + self.single_str.insert(s, ops); + return; + } + Value::I64(n) => { + self.single_u64 + .insert(EntityKeyShape::tag_u64(VariantTag::I64, n as u64), ops); + return; + } + Value::F64(f) if !f.is_nan() => { + self.single_u64 + .insert(EntityKeyShape::tag_u64(VariantTag::F64, f.to_bits()), ops); + return; + } + Value::Bool(b) => { + self.single_u64 + .insert(EntityKeyShape::tag_u64(VariantTag::Bool, b as u64), ops); + return; + } + Value::Datetime(ms) => { + self.single_u64.insert( + EntityKeyShape::tag_u64(VariantTag::Datetime, ms as u64), + ops, + ); + return; + } + _ => {} + } + } + self.multi.insert(key, ops); } @@ -568,8 +631,8 @@ impl AggStateTable { match val { Value::Str(s) => { // single_str is the primary path for string-typed group keys. - // Fall back to multi for entries inserted via insert_from_entity_key - // (snapshot recovery path uses multi unconditionally). + // Fall back to multi for legacy entries inserted before + // snapshot recovery restored keys into their hot-path shape. if let Some(ops) = self.single_str.get(s) { ops } else { @@ -717,26 +780,23 @@ impl AggStateTable { let key_name = self.group_keys.first().cloned().unwrap_or_default(); - // Reconstruct EntityKey from single_u64 entries. + // Reconstruct EntityKey from single_u64 entries. Preserve the typed + // Value variant so snapshot load restores into single_u64 again. for (k, v) in &self.single_u64 { let tag = k >> 60; let payload = k & 0x0FFF_FFFF_FFFF_FFFF; - let canonical: CompactString = match tag { - 1 => (payload as i64).to_string().into(), + let value = match tag { + 1 => Value::I64(payload as i64), 2 => { // F64: restore bits; upper 4 bits were replaced by tag=2. - let f = f64::from_bits(payload | (2u64 << 60)); - format!("{:?}", f).into() + Value::F64(f64::from_bits(payload | (2u64 << 60))) } - 3 => (payload != 0).to_string().into(), - 4 => (payload as i64).to_string().into(), - _ => "unknown".into(), + 3 => Value::Bool(payload != 0), + 4 => Value::Datetime(payload as i64), + _ => Value::Str("unknown".into()), }; let mut pairs: SmallVec<[(CompactString, Value); 2]> = SmallVec::new(); - pairs.push(( - CompactString::from(key_name.as_str()), - Value::Str(canonical), - )); + pairs.push((CompactString::from(key_name.as_str()), value)); entries.push((EntityKey(pairs), v)); } @@ -936,6 +996,72 @@ mod tests { } } + #[test] + fn insert_from_entity_key_restores_single_str_hot_shape() { + let desc = make_descriptor("A", "S", &["user_id"], &[("cnt", count_op_desc())]); + let mut table = AggStateTable::new(); + table.insert_from_entity_key( + make_user_key("alice"), + vec![AggOp::Count(crate::agg_state::CountState { n: 5 })], + ); + + assert_eq!(table.single_str.len(), 1); + assert!(table.multi.is_empty()); + + let event_row = Row::new().with_field("user_id", Value::Str("alice".into())); + let shape = EntityKeyShape::from_row(&desc.group_keys, &event_row).expect("shape"); + let ops = table.get_or_init_by_shape(&shape, &desc); + ops[0].update(&event_row, 0, None, true); + + assert_eq!(ops[0].query(0), Value::I64(6)); + } + + #[test] + fn snapshot_roundtrip_restores_single_u64_hot_shape() { + let desc = make_descriptor("A", "S", &["user_id"], &[("cnt", count_op_desc())]); + let event_row = Row::new().with_field("user_id", Value::I64(42)); + let shape = EntityKeyShape::from_row(&desc.group_keys, &event_row).expect("shape"); + + let mut table = AggStateTable::new(); + { + let ops = table.get_or_init_by_shape(&shape, &desc); + ops[0].update(&event_row, 0, None, true); + } + + let mut restored = AggStateTable::new(); + for (key, ops) in table.iter_sorted() { + restored.insert_from_entity_key(key, ops.clone()); + } + + assert_eq!(restored.single_u64.len(), 1); + assert!(restored.single_str.is_empty()); + assert!(restored.multi.is_empty()); + + let ops = restored.get_or_init_by_shape(&shape, &desc); + ops[0].update(&event_row, 0, None, true); + assert_eq!(ops[0].query(0), Value::I64(2)); + } + + #[test] + fn insert_from_entity_key_with_types_coerces_legacy_i64_string() { + let desc = make_descriptor("A", "S", &["user_id"], &[("cnt", count_op_desc())]); + let mut table = AggStateTable::new(); + table.insert_from_entity_key_with_types( + make_user_key_from_i64(42), + vec![AggOp::Count(crate::agg_state::CountState { n: 5 })], + Some(&[FieldType::I64]), + ); + + assert_eq!(table.single_u64.len(), 1); + assert!(table.single_str.is_empty()); + + let event_row = Row::new().with_field("user_id", Value::I64(42)); + let shape = EntityKeyShape::from_row(&desc.group_keys, &event_row).expect("shape"); + let ops = table.get_or_init_by_shape(&shape, &desc); + ops[0].update(&event_row, 0, None, true); + assert_eq!(ops[0].query(0), Value::I64(6)); + } + #[test] fn agg_state_table_entity_count_counts_distinct_keys() { let desc = make_descriptor("A", "S", &["user_id"], &[("cnt", count_op_desc())]); diff --git a/crates/beava-core/tests/snapshot_lock_hold_repro.rs b/crates/beava-core/tests/snapshot_lock_hold_repro.rs new file mode 100644 index 00000000..2981cdce --- /dev/null +++ b/crates/beava-core/tests/snapshot_lock_hold_repro.rs @@ -0,0 +1,192 @@ +//! Local reproduction of the kalshi-pulse incident (2026-05-21): +//! measure how long `state_tables.lock()` is held during snapshot encoding. +//! +//! The hot operation under the `parking_lot::Mutex` in +//! `crates/beava-server/src/snapshot_task.rs::do_snapshot` is exactly: +//! +//! for (node_name, desc) in registry.compiled_aggregations.iter() { +//! if let Some(table) = state_tables.get(agg_id) { +//! let entries: Vec<(EntityKey, Vec)> = table +//! .iter_sorted() +//! .map(|(k, v)| (k.clone(), v.clone())) // ← clone every entry +//! .collect(); +//! serialized_tables.insert(node_name.clone(), entries); +//! } +//! } +//! +//! We bypass the Registry plumbing and time the inner clone-collect directly +//! on a populated `AggStateTable`. This is the SAME byte-for-byte operation +//! that parks the apply thread in production, just without the registry +//! enumeration overhead (which is negligible — BTreeMap of ~14 aggs). +//! +//! Run with: +//! cargo test -p beava-core --release --test snapshot_lock_hold_repro -- --nocapture +//! +//! Use `--release` — debug-mode `AggOp::clone` is ~10× slower than release +//! and would mislead the projection. + +use beava_core::agg_op::AggOp; +use beava_core::agg_state::CountState; +use beava_core::agg_state_table::{AggStateTable, EntityKey}; +use beava_core::row::Value; +use compact_str::CompactString; +use smallvec::smallvec; +use std::time::Instant; + +/// What op shape to put in each entry. Count is the smallest variant; +/// CountDistinct is a representative sketch (HLL with 1024 registers per +/// entity). +#[derive(Copy, Clone)] +enum OpShape { + Count, + CountDistinctHll1024, +} + +impl OpShape { + fn build(self, n: u64) -> AggOp { + match self { + OpShape::Count => AggOp::Count(CountState { n }), + OpShape::CountDistinctHll1024 => AggOp::CountDistinct(Box::default()), + } + } + fn label(self) -> &'static str { + match self { + OpShape::Count => "Count", + OpShape::CountDistinctHll1024 => "CountDistinct(HLL-1024)", + } + } +} + +/// Populate one `AggStateTable` with N entities; every entry has a single +/// op of the requested shape. +fn build_table(n_entities: usize, shape: OpShape) -> AggStateTable { + let mut table = AggStateTable::new(); + for ent in 0..n_entities { + let key_str = format!("user_{ent:09}"); + let entity_key = EntityKey(smallvec![( + CompactString::from("user_id"), + Value::Str(CompactString::from(key_str.as_str())), + )]); + table.insert_from_entity_key(entity_key, vec![shape.build(ent as u64)]); + } + table +} + +/// The exact clone-collect that runs under `state_tables.lock()` in +/// `snapshot_task.rs::do_snapshot`. Returns (lock_held_ms, entries_collected, +/// approx_bytes_cloned). +fn measure_lock_hold(table: &AggStateTable) -> (f64, usize, usize) { + let t0 = Instant::now(); + let entries: Vec<(EntityKey, Vec)> = table + .iter_sorted() + .map(|(k, v)| (k.clone(), v.clone())) + .collect(); + let elapsed_ms = t0.elapsed().as_secs_f64() * 1000.0; + + // Rough byte estimate: AggOp ≤ 80 B (CI tripwire). EntityKey is a SmallVec + // of (CompactString, Value::Str(CompactString)). Inline string fit varies; + // assume ~32 B per EntityKey on average for "user_NNNNNNNNN" keys. + let n = entries.len(); + let approx_bytes = n * (80 + 32 + 24); // AggOp + EntityKey + Vec overhead + (elapsed_ms, n, approx_bytes) +} + +fn run_shape(label: &str, shape: OpShape, sizes: &[usize]) -> Vec<(usize, f64)> { + println!(); + println!("=== {label} ==="); + println!( + "{:>12} {:>14} {:>18}", + "entities", "lock_held_ms", "ns_per_entry" + ); + println!("{}", "-".repeat(48)); + + let mut out = Vec::new(); + for &n in sizes { + let table = build_table(n, shape); + let _ = measure_lock_hold(&table); // warm-up + let mut samples: Vec = (0..3).map(|_| measure_lock_hold(&table).0).collect(); + samples.sort_by(|a, b| a.partial_cmp(b).unwrap()); + let median_ms = samples[1]; + let ns_per_entry = median_ms * 1_000_000.0 / (n as f64); + out.push((n, ns_per_entry)); + println!("{:>12} {:>11.1}ms {:>15.0}ns", n, median_ms, ns_per_entry); + } + out +} + +#[test] +#[ignore = "diagnostic repro: allocates millions of entries; run manually in release with --ignored --nocapture"] +fn measure_snapshot_lock_hold_time() { + println!(); + println!("=== state_tables.lock() hold-time measurement ==="); + println!("Operation timed (the exact body of the parking_lot lock-hold in"); + println!("crates/beava-server/src/snapshot_task.rs::do_snapshot):"); + println!(" table.iter_sorted().map(|(k,v)| (k.clone(), v.clone())).collect()"); + + let small = &[ + 10_000usize, + 100_000, + 500_000, + 1_000_000, + 2_000_000, + 4_000_000, + ]; + let small_sketch = &[10_000usize, 100_000, 500_000]; + + let count_samples = run_shape(OpShape::Count.label(), OpShape::Count, small); + let hll_samples = run_shape( + OpShape::CountDistinctHll1024.label(), + OpShape::CountDistinctHll1024, + small_sketch, + ); + + // Average ns/entry at large-N (skip the noisy small ones). + let count_ns: f64 = { + let tail: Vec = count_samples + .iter() + .rev() + .take(2) + .map(|(_, n)| *n) + .collect(); + tail.iter().sum::() / tail.len() as f64 + }; + let hll_ns: f64 = { + let tail: Vec = hll_samples.iter().rev().take(2).map(|(_, n)| *n).collect(); + tail.iter().sum::() / tail.len() as f64 + }; + + println!(); + println!("=== Projection to production scale ==="); + println!("Per-entry clone cost (large-N median):"); + println!(" Count : {count_ns:>8.0} ns"); + println!( + " CountDistinct(HLL-1024) : {hll_ns:>8.0} ns ({:.1}× Count)", + hll_ns / count_ns + ); + println!(); + println!("For the 507 MB encoded production snapshot:"); + println!("(actual entry count depends on op-mix; we project two cases)"); + for entries in &[1_000_000usize, 5_000_000usize, 10_000_000usize] { + let count_s = count_ns * (*entries as f64) / 1_000_000_000.0; + let hll_s = hll_ns * (*entries as f64) / 1_000_000_000.0; + println!(" {entries:>10} entries → Count: {count_s:>5.2}s HLL: {hll_s:>6.2}s lock-hold",); + } + + println!(); + println!("=== Interpretation ==="); + println!("/ping is FIFO-queued behind any push waiting on state_tables.lock()."); + println!("Once the lock is held by the snapshot task, no push can dispatch,"); + println!("and /ping (handled on the same single-threaded apply loop) cannot"); + println!("progress until the lock is released."); + println!(); + println!("Even with all-Count workloads, multi-second lock-holds at 5-10M"); + println!("entities are enough to blow past a 3s docker healthcheck timeout."); + println!("Real production workloads with sketches push this to tens of"); + println!("seconds, which matches the incident's 60-90s observation."); + println!(); + println!("Additional time accrues OUTSIDE the lock (encode + WAL truncate +"); + println!("fsync of 507 MB) — those don't park the apply thread directly,"); + println!("but they extend the snapshot task's wall-clock cycle, and once"); + println!("CPU/IO bandwidth is saturated, the next snapshot tick fires before"); + println!("the previous one has fully drained, compounding the problem."); +} diff --git a/crates/beava-persistence/src/fsync_worker.rs b/crates/beava-persistence/src/fsync_worker.rs index 23cb0f9b..a9786836 100644 --- a/crates/beava-persistence/src/fsync_worker.rs +++ b/crates/beava-persistence/src/fsync_worker.rs @@ -67,6 +67,7 @@ pub enum SyncMode { struct AppendRequest { record_type: RecordType, payload: Vec, + min_lsn: Lsn, mode: SyncMode, done: oneshot::Sender>, } @@ -130,6 +131,7 @@ impl WalSink { req = append_rx.recv() => { match req { Some(req) => { + next_lsn = next_lsn.max(req.min_lsn); let assigned = next_lsn; next_lsn = next_lsn.saturating_add(1); // Advance the durable watermark immediately — @@ -194,7 +196,20 @@ impl WalSink { record_type: RecordType, payload: Vec, ) -> Result { - self.append_record_with_mode(record_type, payload, SyncMode::PerEvent) + self.append_record_with_mode_at_least(record_type, payload, 0, SyncMode::PerEvent) + .await + } + + /// Strict append that first raises the assigned LSN to at least + /// `min_lsn`. Used when another WAL stream has already advanced the + /// logical LSN namespace. + pub async fn append_record_at_least( + &self, + record_type: RecordType, + payload: Vec, + min_lsn: Lsn, + ) -> Result { + self.append_record_with_mode_at_least(record_type, payload, min_lsn, SyncMode::PerEvent) .await } @@ -207,12 +222,24 @@ impl WalSink { record_type: RecordType, payload: Vec, mode: SyncMode, + ) -> Result { + self.append_record_with_mode_at_least(record_type, payload, 0, mode) + .await + } + + async fn append_record_with_mode_at_least( + &self, + record_type: RecordType, + payload: Vec, + min_lsn: Lsn, + mode: SyncMode, ) -> Result { let (tx, rx) = oneshot::channel(); self.append_tx .send(AppendRequest { record_type, payload, + min_lsn, mode, done: tx, }) @@ -468,6 +495,7 @@ fn stage_request( next_lsn: &mut Lsn, staged_bytes: &mut u64, ) -> Option { + *next_lsn = (*next_lsn).max(req.min_lsn); let lsn = *next_lsn; *next_lsn += 1; let payload_len = req.payload.len(); diff --git a/crates/beava-persistence/src/lib.rs b/crates/beava-persistence/src/lib.rs index 0c39df7b..b5037643 100644 --- a/crates/beava-persistence/src/lib.rs +++ b/crates/beava-persistence/src/lib.rs @@ -74,7 +74,9 @@ pub use error::{PersistError, SnapshotError}; pub use fsync_worker::{SyncMode, WalSink, WalSinkConfig}; pub use reader::WalReader; pub use record::FORMAT_VERSION; -pub use snapshot::{list_snapshots, prune_old_snapshots, SnapshotReader, SnapshotWriter}; +pub use snapshot::{ + list_snapshots, prune_old_snapshots, SnapshotReader, SnapshotWriteStats, SnapshotWriter, +}; pub use snapshot_header::{ SnapshotHeader, SNAPSHOT_EXT, SNAPSHOT_FORMAT_VERSION, SNAPSHOT_HEADER_SIZE, SNAPSHOT_MAGIC, }; diff --git a/crates/beava-persistence/src/snapshot.rs b/crates/beava-persistence/src/snapshot.rs index 8c4d019d..4dd70c55 100644 --- a/crates/beava-persistence/src/snapshot.rs +++ b/crates/beava-persistence/src/snapshot.rs @@ -15,7 +15,7 @@ use std::fs::{File, OpenOptions}; use std::io::{Read, Write}; use std::path::{Path, PathBuf}; -use std::time::{SystemTime, UNIX_EPOCH}; +use std::time::{Duration, Instant, SystemTime, UNIX_EPOCH}; use crate::error::{PersistError, SnapshotError}; use crate::snapshot_header::{ @@ -34,6 +34,25 @@ use crate::Lsn; /// that still hold a writer handle. pub struct SnapshotWriter; +/// Best-effort instrumentation returned by [`SnapshotWriter::write_with_stats`]. +#[derive(Debug, Clone)] +pub struct SnapshotWriteStats { + pub path: PathBuf, + /// Header bytes plus body bytes written to the committed snapshot file. + pub bytes: u64, + /// Required file fsync duration. + pub file_fsync_duration: Duration, + /// Best-effort parent-directory fsync duration. `None` when unsupported or + /// when opening the directory failed. + pub dir_fsync_duration: Option, +} + +impl SnapshotWriteStats { + pub fn total_fsync_duration(&self) -> Duration { + self.file_fsync_duration + self.dir_fsync_duration.unwrap_or_default() + } +} + impl SnapshotWriter { /// Construct a no-op snapshot writer for `Persistence::Memory` mode. pub fn no_op() -> Self { @@ -54,6 +73,16 @@ impl SnapshotWriter { registry_version: u64, body: &[u8], ) -> Result { + Self::write_with_stats(dir, snapshot_lsn, registry_version, body).map(|stats| stats.path) + } + + /// Atomically write a snapshot file and return write/fsync stats. + pub fn write_with_stats( + dir: &Path, + snapshot_lsn: Lsn, + registry_version: u64, + body: &[u8], + ) -> Result { std::fs::create_dir_all(dir).map_err(PersistError::Io)?; let tmp_path = dir.join(format!("snapshot-{snapshot_lsn:016x}.tmp")); let final_path = dir.join(format!("snapshot-{snapshot_lsn:016x}.{SNAPSHOT_EXT}")); @@ -74,6 +103,7 @@ impl SnapshotWriter { body_crc32c, }; let header_bytes = header.encode(); + let bytes = header_bytes.len() as u64 + body.len() as u64; let mut f = OpenOptions::new() .read(true) @@ -85,21 +115,34 @@ impl SnapshotWriter { f.write_all(&header_bytes).map_err(PersistError::Io)?; f.write_all(body).map_err(PersistError::Io)?; + let file_fsync_started = Instant::now(); f.sync_all().map_err(PersistError::Io)?; + let file_fsync_duration = file_fsync_started.elapsed(); drop(f); std::fs::rename(&tmp_path, &final_path).map_err(PersistError::Io)?; + #[cfg(unix)] + let mut dir_fsync_duration = None; + #[cfg(not(unix))] + let dir_fsync_duration = None; // Best-effort parent-directory fsync makes the rename durable on // filesystems that don't journal directory entries with the file. #[cfg(unix)] { if let Ok(d) = File::open(dir) { + let dir_fsync_started = Instant::now(); let _ = d.sync_all(); + dir_fsync_duration = Some(dir_fsync_started.elapsed()); } } - Ok(final_path) + Ok(SnapshotWriteStats { + path: final_path, + bytes, + file_fsync_duration, + dir_fsync_duration, + }) } } diff --git a/crates/beava-persistence/tests/fsync_worker.rs b/crates/beava-persistence/tests/fsync_worker.rs index 0c9ed903..0aaaf624 100644 --- a/crates/beava-persistence/tests/fsync_worker.rs +++ b/crates/beava-persistence/tests/fsync_worker.rs @@ -49,6 +49,35 @@ async fn append_returns_durable_lsn() { assert_eq!(recs[0].lsn, 1); } +#[tokio::test(flavor = "current_thread")] +async fn append_record_at_least_raises_assigned_lsn() { + let dir = tempfile::tempdir().unwrap(); + let (sink, handle) = WalSink::spawn(config_for_test(dir.path().to_path_buf())).unwrap(); + + let lsn = sink + .append_record_at_least( + beava_persistence::RecordType::RegistryBump, + b"x".to_vec(), + 100, + ) + .await + .unwrap(); + assert_eq!(lsn, 100); + + let next = sink.append_event(b"p".to_vec()).await.unwrap(); + assert_eq!(next, 101); + + sink.shutdown().await.unwrap(); + handle.await.unwrap(); + + let seg = find_segment(dir.path()); + let r = WalReader::open(&seg).unwrap(); + let recs: Vec<_> = r.collect::>().unwrap(); + assert_eq!(recs.len(), 2); + assert_eq!(recs[0].lsn, 100); + assert_eq!(recs[1].lsn, 101); +} + #[tokio::test(flavor = "current_thread")] async fn concurrent_appends_get_distinct_lsns() { let dir = tempfile::tempdir().unwrap(); diff --git a/crates/beava-persistence/tests/snapshot_roundtrip.rs b/crates/beava-persistence/tests/snapshot_roundtrip.rs index 4e3b9a8b..a206be83 100644 --- a/crates/beava-persistence/tests/snapshot_roundtrip.rs +++ b/crates/beava-persistence/tests/snapshot_roundtrip.rs @@ -87,6 +87,22 @@ fn snapshot_write_then_read_roundtrip() { assert_eq!(body_read, body); } +#[test] +fn snapshot_write_with_stats_reports_bytes_and_fsync_timing() { + let tmp = tempfile::tempdir().expect("tempdir"); + let body = b"instrumented payload".to_vec(); + let stats = SnapshotWriter::write_with_stats(tmp.path(), 1001, 3, &body).expect("write"); + + assert!(stats.path.exists()); + assert_eq!(stats.bytes, SNAPSHOT_HEADER_SIZE as u64 + body.len() as u64); + assert!(stats.total_fsync_duration() >= stats.file_fsync_duration); + #[cfg(unix)] + assert!( + stats.dir_fsync_duration.is_some(), + "unix snapshot writes should attempt parent-dir fsync" + ); +} + #[test] fn snapshot_body_corruption_detected() { let tmp = tempfile::tempdir().expect("tempdir"); diff --git a/crates/beava-runtime-core/src/lib.rs b/crates/beava-runtime-core/src/lib.rs index 362f91ba..145a130f 100644 --- a/crates/beava-runtime-core/src/lib.rs +++ b/crates/beava-runtime-core/src/lib.rs @@ -42,5 +42,5 @@ pub use router::{Route, Router}; pub use tcp_listener::TcpListener; pub use wal_buffer::{WalBuffer, WalBufferRing}; pub use wal_lsn::{Lsn, WalLsn}; -pub use wal_writer::WalWriter; +pub use wal_writer::{WalReclaimHandle, WalWriter}; pub use wire_request::WireRequest; diff --git a/crates/beava-runtime-core/src/tcp_listener.rs b/crates/beava-runtime-core/src/tcp_listener.rs index aad8fdd7..8869983f 100644 --- a/crates/beava-runtime-core/src/tcp_listener.rs +++ b/crates/beava-runtime-core/src/tcp_listener.rs @@ -16,6 +16,7 @@ use beava_core::wire::{ OP_PUSH, OP_REGISTER, OP_RESET, }; use bytes::BytesMut; +use std::borrow::Cow; use std::net::SocketAddr; use crate::wire_request::WireRequest; @@ -502,7 +503,7 @@ impl std::error::Error for JsonEnvelopeError {} /// hand-rolled scanner walks key/value pairs and tracks string state + brace /// depth for the body value range. #[inline] -pub fn parse_json_envelope(payload: &[u8]) -> Result<(&str, &[u8]), JsonEnvelopeError> { +pub fn parse_json_envelope(payload: &[u8]) -> Result<(Cow<'_, str>, &[u8]), JsonEnvelopeError> { // Skip optional leading whitespace, then the opening brace. let mut p = skip_ws(payload, 0); if p >= payload.len() || payload[p] != b'{' { @@ -510,7 +511,7 @@ pub fn parse_json_envelope(payload: &[u8]) -> Result<(&str, &[u8]), JsonEnvelope } p += 1; - let mut event_name: Option<&str> = None; + let mut event_name: Option> = None; let mut body_slice: Option<&[u8]> = None; loop { @@ -546,10 +547,7 @@ pub fn parse_json_envelope(payload: &[u8]) -> Result<(&str, &[u8]), JsonEnvelope } let v_start = p + 1; let v_end = scan_string_end(payload, v_start)?; - event_name = Some( - std::str::from_utf8(&payload[v_start..v_end]) - .map_err(|_| JsonEnvelopeError::Decode("invalid utf-8".to_string()))?, - ); + event_name = Some(decode_json_string_fragment(payload, v_start, v_end)?); p = v_end + 1; } "body" => { @@ -589,6 +587,26 @@ pub fn parse_json_envelope(payload: &[u8]) -> Result<(&str, &[u8]), JsonEnvelope )) } +fn decode_json_string_fragment( + payload: &[u8], + start: usize, + end: usize, +) -> Result, JsonEnvelopeError> { + let raw = std::str::from_utf8(&payload[start..end]) + .map_err(|_| JsonEnvelopeError::Decode("invalid utf-8".to_string()))?; + if !raw.as_bytes().contains(&b'\\') { + return Ok(Cow::Borrowed(raw)); + } + + let mut quoted = Vec::with_capacity(raw.len() + 2); + quoted.push(b'"'); + quoted.extend_from_slice(raw.as_bytes()); + quoted.push(b'"'); + serde_json::from_slice::("ed) + .map(Cow::Owned) + .map_err(|e| JsonEnvelopeError::Decode(format!("invalid string escape: {e}"))) +} + /// Skip ASCII whitespace (space/tab/newline/CR). #[inline(always)] fn skip_ws(payload: &[u8], mut p: usize) -> usize { @@ -1133,6 +1151,16 @@ mod tests { assert_eq!(body_val["q"], "a\"b"); } + #[test] + fn parse_json_envelope_decodes_escaped_event_name() { + let payload = br#"{"event":"Txn\u0001","body":{"amount":99}}"#; + let (event, body_bytes) = parse_json_envelope(payload).expect("ok"); + assert_eq!(event.as_ref(), "Txn\u{0001}"); + let body_val: serde_json::Value = + sonic_rs::from_slice(body_bytes).expect("body parses as json"); + assert_eq!(body_val["amount"], 99); + } + #[test] fn parse_json_envelope_malformed_returns_err() { // Missing closing brace. diff --git a/crates/beava-runtime-core/src/wal_lsn.rs b/crates/beava-runtime-core/src/wal_lsn.rs index b4ebcd22..d314b811 100644 --- a/crates/beava-runtime-core/src/wal_lsn.rs +++ b/crates/beava-runtime-core/src/wal_lsn.rs @@ -93,10 +93,18 @@ impl std::fmt::Debug for WalLsn { impl WalLsn { /// Create a new `WalLsn` with all watermarks at zero. pub fn new() -> Self { + Self::new_at(0) + } + + /// Create a new `WalLsn` with all watermarks already advanced to `lsn`. + /// + /// Used after recovery so the hand-rolled WAL ring continues from the + /// recovered high-water mark instead of reusing low LSNs after restart. + pub fn new_at(lsn: Lsn) -> Self { Self { - committed: AtomicU64::new(0), - written: AtomicU64::new(0), - synced: AtomicU64::new(0), + committed: AtomicU64::new(lsn), + written: AtomicU64::new(lsn), + synced: AtomicU64::new(lsn), synced_condvar: Condvar::new(), synced_mutex: Mutex::new(()), } @@ -135,6 +143,18 @@ impl WalLsn { self.committed.fetch_add(n, Ordering::AcqRel) + n } + /// Raise the committed watermark to at least `lsn` without appending + /// bytes to the hand-rolled WAL. + /// + /// The server uses one logical LSN namespace across the legacy + /// `WalSink` registry WAL and the data-plane ring WAL. When a registry + /// bump advances the legacy WAL first, the next data-plane append must + /// jump past that durable point so snapshots can gate both WAL streams + /// with a single LSN. + pub fn mark_committed_at_least(&self, lsn: Lsn) { + self.committed.fetch_max(lsn, Ordering::AcqRel); + } + /// Advance `written_lsn` to at least `lsn`. /// /// Called by the writer thread after `write(fd, ...)` returns. diff --git a/crates/beava-runtime-core/src/wal_writer.rs b/crates/beava-runtime-core/src/wal_writer.rs index 5d545dcf..62b4b839 100644 --- a/crates/beava-runtime-core/src/wal_writer.rs +++ b/crates/beava-runtime-core/src/wal_writer.rs @@ -42,7 +42,7 @@ use crate::wal_lsn::WalLsn; use std::fs::{File, OpenOptions}; use std::io::Write as IoWrite; use std::path::{Path, PathBuf}; -use std::sync::atomic::{AtomicBool, Ordering}; +use std::sync::atomic::{AtomicBool, AtomicU64, Ordering}; use std::sync::Arc; use std::thread::JoinHandle; use std::time::Duration; @@ -90,6 +90,8 @@ impl From for WalWriterError { pub struct WalWriter { /// Open WAL segment file (O_APPEND | O_WRONLY | O_CREAT). file: File, + /// Stable WAL path. The writer owns all truncate/compact operations. + wal_path: PathBuf, /// Shared buffer ring — writer pops sealed buffers from here. ring: Arc, /// Shared LSN watermarks — writer advances written + synced here. @@ -98,6 +100,34 @@ pub struct WalWriter { tick_ms: u64, /// Set to `true` by `shutdown()` to ask the writer thread to drain and exit. shutdown: Arc, + /// Snapshot-covered LSN requested by the snapshot task. The writer is the + /// only thread that acts on this request because it owns the append file. + reclaim: WalReclaimHandle, +} + +/// Handle used by snapshot/checkpoint code to request hand-rolled WAL +/// compaction. Requests are monotone; the writer thread observes them after a +/// flush+fsync boundary and safely rewrites the WAL tail. +#[derive(Clone, Debug)] +pub struct WalReclaimHandle { + requested_lsn: Arc, +} + +impl WalReclaimHandle { + fn new() -> Self { + Self { + requested_lsn: Arc::new(AtomicU64::new(0)), + } + } + + /// Request reclamation of WAL records covered by `covered_lsn`. + pub fn request_reclaim_up_to(&self, covered_lsn: u64) { + self.requested_lsn.fetch_max(covered_lsn, Ordering::AcqRel); + } + + fn requested_lsn(&self) -> u64 { + self.requested_lsn.load(Ordering::Acquire) + } } impl WalWriter { @@ -121,6 +151,7 @@ impl WalWriter { } let wal_path = dir.join("wal-0000000000000000.wal"); + repair_wal_file_tail(&wal_path)?; let file = OpenOptions::new() .create(true) .append(true) @@ -128,10 +159,12 @@ impl WalWriter { Ok(Self { file, + wal_path, ring, lsn, tick_ms, shutdown: Arc::new(AtomicBool::new(false)), + reclaim: WalReclaimHandle::new(), }) } @@ -140,23 +173,32 @@ impl WalWriter { Arc::clone(&self.shutdown) } + /// Return a handle for snapshot/checkpoint code to request WAL + /// reclamation. The writer performs the actual compaction on its own + /// thread after flushing the ring. + pub fn reclaim_handle(&self) -> WalReclaimHandle { + self.reclaim.clone() + } + /// Start the writer + fsync loop in a dedicated `std::thread`. /// /// The returned `JoinHandle` can be awaited for clean shutdown. pub fn spawn(self) -> JoinHandle<()> { let WalWriter { mut file, + wal_path, ring, lsn, tick_ms, shutdown, + reclaim, } = self; let tick = Duration::from_millis(tick_ms); std::thread::Builder::new() .name("beava-wal-writer".to_owned()) .spawn(move || { - run_writer_loop(&mut file, &ring, &lsn, tick, &shutdown); + run_writer_loop(&mut file, &wal_path, &ring, &lsn, tick, &shutdown, &reclaim); }) .expect("failed to spawn WAL writer thread") } @@ -164,11 +206,14 @@ impl WalWriter { fn run_writer_loop( file: &mut File, + wal_path: &Path, ring: &WalBufferRing, lsn: &WalLsn, tick: Duration, shutdown: &AtomicBool, + reclaim: &WalReclaimHandle, ) { + let mut reclaimed_lsn = 0u64; loop { std::thread::sleep(tick); @@ -178,12 +223,14 @@ fn run_writer_loop( // 2. Drain all sealed buffers: write → fsync → free. flush_sealed_buffers(file, ring, lsn); + maybe_reclaim_wal_file(file, wal_path, lsn, reclaim, &mut reclaimed_lsn); // 3. Check shutdown after draining. if shutdown.load(Ordering::Acquire) { // Final drain + fsync on shutdown. ring.seal_active(); flush_sealed_buffers(file, ring, lsn); + maybe_reclaim_wal_file(file, wal_path, lsn, reclaim, &mut reclaimed_lsn); break; } } @@ -246,6 +293,256 @@ fn sync_file(file: &mut File) -> std::io::Result<()> { } } +fn maybe_reclaim_wal_file( + file: &mut File, + wal_path: &Path, + lsn: &WalLsn, + reclaim: &WalReclaimHandle, + reclaimed_lsn: &mut u64, +) { + let requested = reclaim.requested_lsn(); + if requested == 0 || requested <= *reclaimed_lsn { + return; + } + let synced_lsn = lsn.synced(); + + match compact_wal_file(file, wal_path, requested) { + Ok(stats) => { + *reclaimed_lsn = requested; + tracing::info!( + target: "beava.wal", + kind = "wal.handrolled_reclaimed", + covered_lsn = requested, + data_plane_synced_lsn = synced_lsn, + before_bytes = stats.before_bytes, + after_bytes = stats.after_bytes, + removed_records = stats.removed_records, + retained_records = stats.retained_records, + "hand-rolled WAL reclaimed after durable snapshot" + ); + } + Err(e) => { + tracing::warn!( + target: "beava.wal", + kind = "wal.handrolled_reclaim_failed", + covered_lsn = requested, + error = %e, + "hand-rolled WAL reclaim skipped" + ); + } + } +} + +#[derive(Debug)] +struct WalCompactStats { + before_bytes: u64, + after_bytes: u64, + removed_records: usize, + retained_records: usize, +} + +#[derive(Debug)] +struct ParsedWalRecord { + lsn: u64, + start: usize, + end: usize, + version: u8, +} + +fn compact_wal_file( + open_append_file: &mut File, + wal_path: &Path, + covered_lsn: u64, +) -> std::io::Result { + open_append_file.sync_all()?; + + let data = std::fs::read(wal_path)?; + let before_bytes = data.len() as u64; + if data.is_empty() { + return Ok(WalCompactStats { + before_bytes, + after_bytes: 0, + removed_records: 0, + retained_records: 0, + }); + } + + let parsed = parse_wal_record_bounds_with_prefix(&data)?; + let records = parsed.records; + let mut retained = Vec::new(); + let mut removed_records = 0usize; + let mut retained_records = 0usize; + for rec in records { + if rec.lsn <= covered_lsn { + removed_records += 1; + continue; + } + if rec.version != 0x03 { + return Err(std::io::Error::new( + std::io::ErrorKind::InvalidData, + "cannot compact retained legacy v2 WAL records without assigned LSNs", + )); + } + retained.extend_from_slice(&data[rec.start..rec.end]); + retained_records += 1; + } + + if removed_records == 0 && parsed.valid_prefix_len == data.len() { + sync_parent_dir(wal_path)?; + return Ok(WalCompactStats { + before_bytes, + after_bytes: before_bytes, + removed_records, + retained_records, + }); + } + + let tmp_path = wal_path.with_extension("wal.compact.tmp"); + match std::fs::remove_file(&tmp_path) { + Ok(()) => {} + Err(e) if e.kind() == std::io::ErrorKind::NotFound => {} + Err(e) => return Err(e), + } + { + let mut tmp = OpenOptions::new() + .write(true) + .create_new(true) + .open(&tmp_path)?; + tmp.write_all(&retained)?; + tmp.sync_all()?; + } + + // Open the replacement WAL before the rename. After rename succeeds there + // must be no fallible reopen step, otherwise a transient fd/open failure + // could leave the writer appending to the old unlinked inode. + let new_append_file = OpenOptions::new().append(true).open(&tmp_path)?; + + std::fs::rename(&tmp_path, wal_path)?; + + *open_append_file = new_append_file; + sync_parent_dir(wal_path)?; + + Ok(WalCompactStats { + before_bytes, + after_bytes: retained.len() as u64, + removed_records, + retained_records, + }) +} + +#[cfg(test)] +fn parse_wal_record_bounds(data: &[u8]) -> std::io::Result> { + Ok(parse_wal_record_bounds_with_prefix(data)?.records) +} + +#[derive(Debug)] +struct ParsedWalRecords { + records: Vec, + valid_prefix_len: usize, +} + +fn parse_wal_record_bounds_with_prefix(data: &[u8]) -> std::io::Result { + let mut records = Vec::new(); + let mut pos = 0usize; + let mut valid_prefix_len = 0usize; + + while pos < data.len() { + let start = pos; + let version = data[pos]; + if version != 0x02 && version != 0x03 { + break; + } + pos += 1; + + let assigned_lsn = if version == 0x03 { + if pos + 8 > data.len() { + break; + } + let lsn = u64::from_be_bytes(data[pos..pos + 8].try_into().unwrap()); + pos += 8; + Some(lsn) + } else { + None + }; + + if pos + 15 > data.len() { + break; + } + pos += 1; // body_format + pos += 4; // registry version + pos += 8; // event time + + let name_len = u16::from_be_bytes(data[pos..pos + 2].try_into().unwrap()) as usize; + pos += 2; + + if pos + name_len + 4 > data.len() { + break; + } + if std::str::from_utf8(&data[pos..pos + name_len]).is_err() { + break; + } + pos += name_len; + + let body_len = u32::from_be_bytes(data[pos..pos + 4].try_into().unwrap()) as usize; + pos += 4; + + if pos + body_len > data.len() { + break; + } + pos += body_len; + + let end = pos; + records.push(ParsedWalRecord { + lsn: assigned_lsn.unwrap_or(end as u64), + start, + end, + version, + }); + valid_prefix_len = end; + } + + Ok(ParsedWalRecords { + records, + valid_prefix_len, + }) +} + +fn repair_wal_file_tail(wal_path: &Path) -> std::io::Result<()> { + let data = match std::fs::read(wal_path) { + Ok(data) => data, + Err(e) if e.kind() == std::io::ErrorKind::NotFound => return Ok(()), + Err(e) => return Err(e), + }; + let parsed = parse_wal_record_bounds_with_prefix(&data)?; + if parsed.valid_prefix_len == data.len() { + return Ok(()); + } + + let file = OpenOptions::new().write(true).open(wal_path)?; + file.set_len(parsed.valid_prefix_len as u64)?; + file.sync_all()?; + sync_parent_dir(wal_path)?; + tracing::warn!( + target: "beava.wal", + kind = "wal.handrolled_tail_repaired", + path = %wal_path.display(), + before_bytes = data.len(), + after_bytes = parsed.valid_prefix_len, + "repaired hand-rolled WAL by truncating invalid tail before append" + ); + Ok(()) +} + +fn sync_parent_dir(path: &Path) -> std::io::Result<()> { + let parent = path.parent().ok_or_else(|| { + std::io::Error::new( + std::io::ErrorKind::InvalidInput, + format!("path has no parent: {}", path.display()), + ) + })?; + File::open(parent)?.sync_all() +} + /// Return `true` if `path` is on a network filesystem (NFS, SMB, FUSE, etc.). /// /// On macOS: uses `statfs` and checks `f_fstypename` for "nfs", "smbfs", @@ -339,3 +636,233 @@ pub fn is_network_fs(path: &Path) -> bool { false } } + +#[cfg(test)] +mod tests { + use super::*; + use std::time::{SystemTime, UNIX_EPOCH}; + + fn temp_dir(name: &str) -> PathBuf { + let nanos = SystemTime::now() + .duration_since(UNIX_EPOCH) + .unwrap() + .as_nanos(); + let dir = std::env::temp_dir().join(format!( + "beava-wal-writer-{name}-{}-{nanos}", + std::process::id() + )); + std::fs::create_dir_all(&dir).unwrap(); + dir + } + + fn encode_v3(buf: &mut Vec, lsn: u64, event_name: &str, body: &[u8]) { + buf.push(0x03); + buf.extend_from_slice(&lsn.to_be_bytes()); + buf.push(0x02); // JSON + buf.extend_from_slice(&1u32.to_be_bytes()); + buf.extend_from_slice(&123u64.to_be_bytes()); + let name_bytes = event_name.as_bytes(); + buf.extend_from_slice(&(name_bytes.len() as u16).to_be_bytes()); + buf.extend_from_slice(name_bytes); + buf.extend_from_slice(&(body.len() as u32).to_be_bytes()); + buf.extend_from_slice(body); + } + + #[test] + fn compact_wal_file_removes_snapshot_covered_v3_records() { + let dir = temp_dir("compact"); + let path = dir.join("wal-0000000000000000.wal"); + let mut bytes = Vec::new(); + encode_v3(&mut bytes, 10, "Txn", br#"{"user_id":"a"}"#); + encode_v3(&mut bytes, 20, "Txn", br#"{"user_id":"b"}"#); + encode_v3(&mut bytes, 30, "Txn", br#"{"user_id":"c"}"#); + std::fs::write(&path, &bytes).unwrap(); + + let mut file = OpenOptions::new() + .create(true) + .append(true) + .open(&path) + .unwrap(); + let stats = compact_wal_file(&mut file, &path, 20).unwrap(); + let compacted = std::fs::read(&path).unwrap(); + let records = parse_wal_record_bounds(&compacted).unwrap(); + + assert_eq!(stats.removed_records, 2); + assert_eq!(stats.retained_records, 1); + assert!(stats.after_bytes < stats.before_bytes); + assert_eq!(records.len(), 1); + assert_eq!(records[0].lsn, 30); + + file.write_all(b"tail").unwrap(); + file.sync_all().unwrap(); + assert!( + std::fs::metadata(&path).unwrap().len() > stats.after_bytes, + "writer must keep appending to the compacted WAL path" + ); + + std::fs::remove_dir_all(dir).unwrap(); + } + + #[test] + fn compact_wal_file_skips_when_no_records_are_covered() { + let dir = temp_dir("noop"); + let path = dir.join("wal-0000000000000000.wal"); + let mut bytes = Vec::new(); + encode_v3(&mut bytes, 50, "Txn", br#"{"user_id":"a"}"#); + std::fs::write(&path, &bytes).unwrap(); + + let mut file = OpenOptions::new() + .create(true) + .append(true) + .open(&path) + .unwrap(); + let stats = compact_wal_file(&mut file, &path, 20).unwrap(); + + assert_eq!(stats.removed_records, 0); + assert_eq!(stats.retained_records, 1); + assert_eq!(std::fs::read(&path).unwrap(), bytes); + + std::fs::remove_dir_all(dir).unwrap(); + } + + #[test] + fn compact_wal_file_ignores_truncated_tail_like_recovery() { + let dir = temp_dir("truncated-tail"); + let path = dir.join("wal-0000000000000000.wal"); + let mut bytes = Vec::new(); + encode_v3(&mut bytes, 10, "Txn", br#"{"user_id":"covered"}"#); + encode_v3(&mut bytes, 30, "Txn", br#"{"user_id":"retained"}"#); + bytes.extend_from_slice(&[0x03, 0, 0, 0]); // torn v3 header + std::fs::write(&path, &bytes).unwrap(); + + let mut file = OpenOptions::new() + .create(true) + .append(true) + .open(&path) + .unwrap(); + let stats = compact_wal_file(&mut file, &path, 10).unwrap(); + let compacted = std::fs::read(&path).unwrap(); + let records = parse_wal_record_bounds(&compacted).unwrap(); + + assert_eq!(stats.removed_records, 1); + assert_eq!(stats.retained_records, 1); + assert_eq!(records.len(), 1); + assert_eq!(records[0].lsn, 30); + + file.write_all(b"tail").unwrap(); + file.sync_all().unwrap(); + assert!( + std::fs::metadata(&path).unwrap().len() > stats.after_bytes, + "writer must keep appending to the renamed compacted WAL" + ); + + std::fs::remove_dir_all(dir).unwrap(); + } + + #[test] + fn compact_wal_file_repairs_truncated_tail_even_without_covered_records() { + let dir = temp_dir("truncated-tail-no-covered"); + let path = dir.join("wal-0000000000000000.wal"); + let mut bytes = Vec::new(); + encode_v3(&mut bytes, 30, "Txn", br#"{"user_id":"retained"}"#); + let valid_len = bytes.len() as u64; + bytes.extend_from_slice(&[0x03, 0, 0, 0]); // torn v3 header + std::fs::write(&path, &bytes).unwrap(); + + let mut file = OpenOptions::new() + .create(true) + .append(true) + .open(&path) + .unwrap(); + let stats = compact_wal_file(&mut file, &path, 10).unwrap(); + let compacted = std::fs::read(&path).unwrap(); + let records = parse_wal_record_bounds(&compacted).unwrap(); + + assert_eq!(stats.removed_records, 0); + assert_eq!(stats.retained_records, 1); + assert_eq!(stats.after_bytes, valid_len); + assert_eq!(records.len(), 1); + assert_eq!(records[0].lsn, 30); + + std::fs::remove_dir_all(dir).unwrap(); + } + + #[test] + fn wal_writer_new_repairs_invalid_tail_before_append() { + let dir = temp_dir("startup-repair"); + let path = dir.join("wal-0000000000000000.wal"); + let mut bytes = Vec::new(); + encode_v3(&mut bytes, 10, "Txn", br#"{"user_id":"covered"}"#); + let valid_len = bytes.len(); + bytes.extend_from_slice(b"stale-garbage-tail"); + std::fs::write(&path, &bytes).unwrap(); + + let ring = Arc::new(WalBufferRing::new(2, 4096, Arc::new(WalLsn::new()))); + let lsn = Arc::new(WalLsn::new()); + let mut writer = WalWriter::new(&dir, ring, lsn, 1).expect("WalWriter::new repairs tail"); + + assert_eq!(std::fs::metadata(&path).unwrap().len(), valid_len as u64); + + let mut appended = Vec::new(); + encode_v3(&mut appended, 20, "Txn", br#"{"user_id":"retained"}"#); + writer.file.write_all(&appended).unwrap(); + writer.file.sync_all().unwrap(); + + let repaired = std::fs::read(&path).unwrap(); + let records = parse_wal_record_bounds(&repaired).unwrap(); + assert_eq!(records.len(), 2); + assert_eq!(records[0].lsn, 10); + assert_eq!(records[1].lsn, 20); + + std::fs::remove_dir_all(dir).unwrap(); + } + + #[test] + fn compact_wal_file_replaces_stale_tmp_from_prior_crash() { + let dir = temp_dir("stale-tmp"); + let path = dir.join("wal-0000000000000000.wal"); + let mut bytes = Vec::new(); + encode_v3(&mut bytes, 10, "Txn", br#"{"user_id":"a"}"#); + std::fs::write(&path, &bytes).unwrap(); + std::fs::write(path.with_extension("wal.compact.tmp"), b"stale").unwrap(); + + let mut file = OpenOptions::new() + .create(true) + .append(true) + .open(&path) + .unwrap(); + let stats = compact_wal_file(&mut file, &path, 10).unwrap(); + + assert_eq!(stats.removed_records, 1); + assert_eq!(stats.after_bytes, 0); + assert_eq!(std::fs::read(&path).unwrap(), b""); + + std::fs::remove_dir_all(dir).unwrap(); + } + + #[test] + fn reclaim_request_can_exceed_data_plane_synced_lsn_for_registry_lsn_gaps() { + let dir = temp_dir("registry-gap"); + let path = dir.join("wal-0000000000000000.wal"); + let mut bytes = Vec::new(); + encode_v3(&mut bytes, 10, "Txn", br#"{"user_id":"a"}"#); + std::fs::write(&path, &bytes).unwrap(); + + let mut file = OpenOptions::new() + .create(true) + .append(true) + .open(&path) + .unwrap(); + let lsn = WalLsn::new_at(10); + let reclaim = WalReclaimHandle::new(); + reclaim.request_reclaim_up_to(100); + let mut reclaimed_lsn = 0; + + maybe_reclaim_wal_file(&mut file, &path, &lsn, &reclaim, &mut reclaimed_lsn); + + assert_eq!(reclaimed_lsn, 100); + assert_eq!(std::fs::read(&path).unwrap(), b""); + + std::fs::remove_dir_all(dir).unwrap(); + } +} diff --git a/crates/beava-server/src/apply_shard.rs b/crates/beava-server/src/apply_shard.rs index 5677ab71..8a9fe7f3 100644 --- a/crates/beava-server/src/apply_shard.rs +++ b/crates/beava-server/src/apply_shard.rs @@ -12,7 +12,7 @@ use crate::register::RegisterPayload; use crate::runtime_core_glue::GlueResponse; use crate::AppState; -use beava_core::row::Row; +use beava_core::row::{Row, Value}; use beava_runtime_core::wal_buffer::WalBufferRing; use beava_runtime_core::wal_lsn::WalLsn; use beava_runtime_core::wire_request::WireRequest; @@ -214,11 +214,9 @@ impl ApplyShard { // categorised-lists schema. `dry_run` fires first (returns // the diff JSON without applying). The force gate runs // second: destructive entries without `force=true` return - // 409 + `force_required`; with `force=true` we eagerly - // remove the conflicting descriptors so - // `execute_register_with_wal` treats the payload as - // additive (`registry_version` bumps, WAL records the - // change). + // 409 + `force_required`; with `force=true` we compute the + // exact removal set but leave the live registry untouched + // until the WAL-backed register path has fsynced the bump. let (force, dry_run) = match serde_json::from_slice::(&payload) { Ok(v) => ( v.get("force").and_then(|x| x.as_bool()).unwrap_or(false), @@ -263,15 +261,11 @@ impl ApplyShard { // `force=true` carries the explicit "drop existing state and // replace fully" intent for any descriptor that already - // exists in the registry. We pre-remove every existing - // descriptor that the new payload would change before - // invoking `execute_register_with_wal`, which delegates - // installation to `Registry::apply_registration` (silently - // skips descriptors already present by name). Without - // pre-removal, an additive change against an existing - // descriptor (e.g. NewField on an existing event source) - // would no-op silently. Two reasons we can't gate solely - // on `diff.destructive`: + // exists in the registry. Compute every existing descriptor + // the new payload would change and record it in the durable + // `RegistryBump`; the WAL-backed path applies the removal + // after fsync. Two reasons we can't gate solely on + // `diff.destructive`: // // 1. `classify_register_diff` classifies new fields on // an existing event source and new aggregations in @@ -283,12 +277,11 @@ impl ApplyShard { // skip — it's genuinely-new (not in current // registry), so there's nothing to pre-remove. // - // Pre-removal drops compiled chains, aggregations, feature - // index entries, and accumulated state for the named - // descriptors. That state loss is the documented `force=true` - // semantic; callers who want to add a field without losing - // state should send the request without `force` (additive - // path is allowed by `register_check_force_required`). + // Forced removal drops compiled chains, aggregations, feature + // index entries, and the old agg slots become unreachable. + // That state loss is the documented `force=true` semantic; + // callers who want to add a field without losing state should + // send the request without `force`. let mut force_removed: Vec = Vec::new(); if force { let mut to_remove: Vec = Vec::new(); @@ -385,12 +378,6 @@ impl ApplyShard { to_remove.dedup(); } - if !to_remove.is_empty() { - self.state - .dev_agg - .registry - .force_remove_descriptors(&to_remove); - } // Captured for the RegistryBump WAL record so recovery // can replay the same force-removal closure BEFORE // re-applying `payload_nodes` — without this, replay @@ -402,6 +389,11 @@ impl ApplyShard { // function on a one-shot single-threaded tokio runtime so // we don't pull tokio into the hot path. let state_clone = Arc::clone(&self.state); + let registry_bump_min_lsn = state_clone + .dev_agg + .next_event_id + .load(std::sync::atomic::Ordering::Acquire) + .saturating_add(1); let rt = tokio::runtime::Builder::new_current_thread() .enable_all() .build() @@ -411,6 +403,7 @@ impl ApplyShard { reg_payload, &state_clone.wal_sink, force_removed, + registry_bump_min_lsn, )); // Grow `state_tables` so the hot path can index by // `desc.agg_id` without bounds issues. Register is rare, @@ -903,6 +896,13 @@ impl ApplyShard { }; let t_parse = t0.map(|t| t.elapsed()); + if string_has_control_chars(event_name) || row_has_control_chars(&row) { + return GlueResponse::PushError { + code: "control_character_in_string", + registry_version, + }; + } + // 2. Lookup event descriptor (Arc-backed; refcount bump only). let descriptor = match self.state.dev_agg.registry.get_event_descriptor(event_name) { Some(d) => d, @@ -987,9 +987,9 @@ impl ApplyShard { let now_ms_i64: i64 = now_ms as i64; let t_validate = t0.map(|t| t.elapsed()); - // 6. Serialize WAL payload — v=2 binary format. + // 6. Serialize WAL payload — v=3 binary format. // - // `[u8 v=2][u8 body_format][u32 rv BE][u64 et_ms BE] + // `[u8 v=3][u64 assigned_lsn BE][u8 body_format][u32 rv BE][u64 et_ms BE] // [u16 event_name_len BE][N bytes name][u32 body_len BE][M bytes body]` // // `body` is the exact bytes received from the wire — zero-copy @@ -999,9 +999,13 @@ impl ApplyShard { let name_bytes = event_name.as_bytes(); let name_len = name_bytes.len() as u16; let body_len = body.len() as u32; - let mut payload_bytes = - Vec::with_capacity(1 + 1 + 4 + 8 + 2 + name_bytes.len() + 4 + body.len()); - payload_bytes.push(0x02u8); + let payload_len = 1 + 8 + 1 + 4 + 8 + 2 + name_bytes.len() + 4 + body.len(); + self.wal_lsn + .mark_committed_at_least(self.state.wal_sink.durable_lsn()); + let expected_ack_lsn = self.wal_lsn.committed().saturating_add(payload_len as u64); + let mut payload_bytes = Vec::with_capacity(payload_len); + payload_bytes.push(0x03u8); + payload_bytes.extend_from_slice(&expected_ack_lsn.to_be_bytes()); payload_bytes.push(body_format); payload_bytes.extend_from_slice(®istry_version.to_be_bytes()); payload_bytes.extend_from_slice(&now_ms.to_be_bytes()); @@ -1013,6 +1017,7 @@ impl ApplyShard { // 7. WAL append — lock-free, no Mutex, no channel. let ack_lsn = self.wal_ring.append(&payload_bytes); + debug_assert_eq!(ack_lsn, expected_ack_lsn); let t_wal_append = t0.map(|t| t.elapsed()); // 8. Apply to aggregations under the table lock (uncontended on @@ -1032,6 +1037,16 @@ impl ApplyShard { &mut tables, descriptor.cold_after_ms, ); + self.state + .dev_agg + .next_event_id + .fetch_max(ack_lsn, Ordering::Release); + if now_ms > 0 { + self.state + .dev_agg + .query_time_ms + .fetch_max(now_ms, Ordering::Release); + } // Refresh the process-static `beava_entity_count_resident` // gauge under the lock we already hold. O(N_tables) sum of // three `HashMap.len()` reads; typically < 30 tables (one @@ -1042,20 +1057,9 @@ impl ApplyShard { } let t_agg = t0.map(|t| t.elapsed()); - // 9. Bump monotonic event counters. `query_time_ms` is fed - // `now_ms` (server wall-clock at apply); the GET path's - // `compute_query_time_ms` reads this watermark to surface a - // meaningful query time for windowed-op queries. - self.state - .dev_agg - .next_event_id - .fetch_max(ack_lsn, Ordering::Relaxed); - if now_ms > 0 { - self.state - .dev_agg - .query_time_ms - .fetch_max(now_ms, Ordering::Relaxed); - } + // 9. Monotonic counters were bumped while holding `state_tables`, so a + // snapshot cannot observe applied table state without the matching + // applied LSN/query-time watermark. let t_bk_counters = t0.map(|t| t.elapsed()); // `t_bk_evid` keeps the trace shape stable; the per-stage delta @@ -1198,6 +1202,38 @@ fn extract_dedupe_str_from_row(row: &beava_core::row::Row, key: &str) -> Option< }) } +fn row_has_control_chars(row: &Row) -> bool { + row.iter() + .any(|(field, value)| string_has_control_chars(field) || value_has_control_chars(value)) +} + +fn value_has_control_chars(value: &Value) -> bool { + match value { + Value::Str(s) => string_has_control_chars(s), + Value::Json(jv) => json_value_has_control_chars(jv), + Value::List(values) => values.iter().any(value_has_control_chars), + Value::Map(map) => map + .iter() + .any(|(key, value)| string_has_control_chars(key) || value_has_control_chars(value)), + _ => false, + } +} + +fn json_value_has_control_chars(value: &serde_json::Value) -> bool { + match value { + serde_json::Value::String(s) => string_has_control_chars(s), + serde_json::Value::Array(values) => values.iter().any(json_value_has_control_chars), + serde_json::Value::Object(map) => map.iter().any(|(key, value)| { + string_has_control_chars(key) || json_value_has_control_chars(value) + }), + _ => false, + } +} + +fn string_has_control_chars(value: &str) -> bool { + value.chars().any(char::is_control) +} + /// One entry in the `OP_BATCH_GET` request payload. /// /// - `table`: aggregation node name. diff --git a/crates/beava-server/src/http_admin.rs b/crates/beava-server/src/http_admin.rs index 8314f115..64a335bc 100644 --- a/crates/beava-server/src/http_admin.rs +++ b/crates/beava-server/src/http_admin.rs @@ -93,6 +93,9 @@ async fn metrics_handler(State(state): State) -> impl IntoResponse { // `categories_capped`; top-k displacement and histogram bucket drops // join when those operator internals expose hooks. let op_cap_hits = entropy_capped; + let snapshot_metrics = crate::snapshot_metrics::snapshot(); + let snapshot_duration_seconds = snapshot_metrics.last_duration_us as f64 / 1_000_000.0; + let snapshot_fsync_seconds = snapshot_metrics.last_fsync_us as f64 / 1_000_000.0; let body = format!( "# HELP beava_registry_version Registry version (monotonic).\n\ @@ -121,7 +124,16 @@ async fn metrics_handler(State(state): State) -> impl IntoResponse { beava_bucket_reclaim_total {bucket_reclaims}\n\ # HELP beava_bytes_per_entity_p99 Static estimate of per-entity memory footprint (~7 KB for a rich 30-feature pack).\n\ # TYPE beava_bytes_per_entity_p99 gauge\n\ - beava_bytes_per_entity_p99 {bytes_per_entity_p99}\n", + beava_bytes_per_entity_p99 {bytes_per_entity_p99}\n\ + # HELP beava_snapshot_last_duration_seconds Wall-clock duration of the last successful snapshot.\n\ + # TYPE beava_snapshot_last_duration_seconds gauge\n\ + beava_snapshot_last_duration_seconds {snapshot_duration_seconds:.6}\n\ + # HELP beava_snapshot_last_bytes Bytes written by the last successful snapshot, including snapshot header and body.\n\ + # TYPE beava_snapshot_last_bytes gauge\n\ + beava_snapshot_last_bytes {snapshot_bytes}\n\ + # HELP beava_snapshot_last_fsync_seconds File plus parent-directory fsync time for the last successful snapshot.\n\ + # TYPE beava_snapshot_last_fsync_seconds gauge\n\ + beava_snapshot_last_fsync_seconds {snapshot_fsync_seconds:.6}\n", registry_version = snap.version, node_count = snap.node_count, entropy_capped = entropy_capped, @@ -130,6 +142,9 @@ async fn metrics_handler(State(state): State) -> impl IntoResponse { entity_count = entity_count, bucket_reclaims = bucket_reclaims, bytes_per_entity_p99 = BYTES_PER_ENTITY_P99_V0_PLACEHOLDER, + snapshot_duration_seconds = snapshot_duration_seconds, + snapshot_bytes = snapshot_metrics.last_bytes, + snapshot_fsync_seconds = snapshot_fsync_seconds, ); ( diff --git a/crates/beava-server/src/lib.rs b/crates/beava-server/src/lib.rs index 2f31f6b1..41662025 100644 --- a/crates/beava-server/src/lib.rs +++ b/crates/beava-server/src/lib.rs @@ -18,7 +18,10 @@ pub mod registry_debug; pub mod runtime_core_glue; pub mod server; pub mod shutdown; +pub mod snapshot_fork; +pub(crate) mod snapshot_metrics; pub mod snapshot_task; +pub mod thp; pub mod wal_config; #[cfg(any(feature = "testing", test))] diff --git a/crates/beava-server/src/recovery.rs b/crates/beava-server/src/recovery.rs index 81e2e84a..dcc69665 100644 --- a/crates/beava-server/src/recovery.rs +++ b/crates/beava-server/src/recovery.rs @@ -2,7 +2,8 @@ //! //! 1. `load_snapshot_if_any(dir, dev_agg)` — descending-LSN scan; first valid //! snapshot wins; install registry descriptors + state tables; return its -//! LSN. Empty dir or all-corrupt files → 0 (cold start). +//! snapshot LSN plus the applied data-plane watermark stored in the body. +//! Empty dir or all-corrupt files → 0 (cold start). //! 2. `replay_wal_from_lsn(wal_dir, snapshot_lsn, dev_agg)` — replay every WAL //! record with `lsn > snapshot_lsn` in LSN order: `Event` decodes its //! payload and feeds `apply_event_to_aggregations`; `RegistryBump` @@ -17,7 +18,7 @@ use beava_core::row::{Row, Value}; use beava_core::snapshot_body::SnapshotBody; use beava_persistence::{list_snapshots, Lsn, PersistError, RecordType, SnapshotReader, WalReader}; use serde::Deserialize; -use std::path::Path; +use std::path::{Path, PathBuf}; use std::sync::atomic::Ordering; /// Outcome counters reported back from `replay_wal_from_lsn`. @@ -27,16 +28,125 @@ pub struct RecoveryOutcome { pub snapshot_lsn: Lsn, pub replay_event_count: u64, pub replay_registry_bumps: u64, + pub quarantined_records: u64, + pub applied_registry_bump_after_snapshot: bool, pub last_lsn: Lsn, } +/// Snapshot recovery result. `snapshot_lsn` comes from the snapshot header and +/// gates legacy persistence-WAL replay. `applied_lsn` comes from the snapshot +/// body and gates hand-rolled data-plane WAL replay, because older snapshots +/// can have a header LSN that does not match the data-plane state already +/// serialized into the body. +#[derive(Debug, Default, Clone, Copy, PartialEq, Eq)] +pub struct SnapshotLoadOutcome { + pub snapshot_lsn: Lsn, + pub applied_lsn: Lsn, +} + +#[derive(Debug, Clone, Copy)] +enum WalQuarantineKind { + HandrolledJsonBody, + HandrolledMsgpackBody, + PersistenceEventPayload, +} + +impl WalQuarantineKind { + fn as_str(self) -> &'static str { + match self { + WalQuarantineKind::HandrolledJsonBody => "handrolled-json-body", + WalQuarantineKind::HandrolledMsgpackBody => "handrolled-msgpack-body", + WalQuarantineKind::PersistenceEventPayload => "persistence-event-payload", + } + } +} + +fn wal_quarantine_marker_path(wal_dir: &Path, lsn: Lsn, kind: WalQuarantineKind) -> PathBuf { + wal_dir + .join("quarantine") + .join(format!("lsn-{lsn:016x}-{}.json", kind.as_str())) +} + +fn wal_quarantine_marker_exists(wal_dir: &Path, lsn: Lsn, kind: WalQuarantineKind) -> bool { + wal_quarantine_marker_path(wal_dir, lsn, kind).exists() +} + +fn quarantine_wal_decode_failure( + wal_dir: &Path, + lsn: Lsn, + kind: WalQuarantineKind, + error: &dyn std::fmt::Display, +) { + let marker = wal_quarantine_marker_path(wal_dir, lsn, kind); + if marker.exists() { + return; + } + + let Some(dir) = marker.parent() else { + return; + }; + if let Err(e) = std::fs::create_dir_all(dir) { + tracing::warn!( + target: "beava.recovery", + kind = "recovery.wal_quarantine_write_failed", + lsn, + quarantine_kind = kind.as_str(), + error = %e, + "failed to create WAL quarantine directory" + ); + return; + } + + let body = serde_json::json!({ + "lsn": lsn, + "kind": kind.as_str(), + "reason": error.to_string(), + }); + let bytes = serde_json::to_vec_pretty(&body).unwrap_or_default(); + let tmp = marker.with_extension(format!("json.tmp-{}", std::process::id())); + if let Err(e) = std::fs::write(&tmp, bytes) { + tracing::warn!( + target: "beava.recovery", + kind = "recovery.wal_quarantine_write_failed", + lsn, + quarantine_kind = kind.as_str(), + error = %e, + "failed to write WAL quarantine marker" + ); + return; + } + if let Err(e) = std::fs::rename(&tmp, &marker) { + let _ = std::fs::remove_file(&tmp); + tracing::warn!( + target: "beava.recovery", + kind = "recovery.wal_quarantine_write_failed", + lsn, + quarantine_kind = kind.as_str(), + marker = %marker.display(), + error = %e, + "failed to commit WAL quarantine marker" + ); + return; + } + + tracing::warn!( + target: "beava.recovery", + kind = "recovery.wal_record_quarantined", + lsn, + quarantine_kind = kind.as_str(), + marker = %marker.display(), + error = %error, + "WAL record decode failed; quarantined for future recovery passes" + ); +} + /// Scan `snapshot_dir` for the highest-LSN valid snapshot; install its /// registry descriptors + state tables into `app_state`. Returns the /// snapshot's LSN, or 0 if no valid snapshot exists (cold start). pub fn load_snapshot_if_any( snapshot_dir: &Path, dev_agg: &DevAggState, -) -> Result { +) -> Result { let snaps = list_snapshots(snapshot_dir)?; for (lsn, path) in snaps { match SnapshotReader::open(&path) { @@ -58,13 +168,28 @@ pub fn load_snapshot_if_any( new_next_agg_id, ); for (node_name, entries) in state_tables { - let agg_id = match dev_agg.registry.compiled_aggregation(&node_name) { - Some(d) => d.agg_id as usize, + let agg_desc = match dev_agg.registry.compiled_aggregation(&node_name) { + Some(d) => d, None => continue, }; + let agg_id = agg_desc.agg_id as usize; + let group_key_types = dev_agg + .registry + .get_event_descriptor(&agg_desc.source_node_name) + .map(|event| { + agg_desc + .group_keys + .iter() + .filter_map(|key| event.schema.fields.get(key).cloned()) + .collect::>() + }); let tbl = &mut tables[agg_id]; for (key, ops) in entries { - tbl.insert_from_entity_key(key, ops); + tbl.insert_from_entity_key_with_types( + key, + ops, + group_key_types.as_deref(), + ); } } } @@ -80,10 +205,14 @@ pub fn load_snapshot_if_any( target: "beava.recovery", kind = "recovery.snapshot_loaded", snapshot_lsn = lsn, + applied_lsn = next_event_id, registry_version = header.registry_version, "loaded snapshot" ); - return Ok(lsn); + return Ok(SnapshotLoadOutcome { + snapshot_lsn: lsn, + applied_lsn: next_event_id, + }); } Err(e) => { tracing::warn!( @@ -108,7 +237,7 @@ pub fn load_snapshot_if_any( } } } - Ok(0) + Ok(SnapshotLoadOutcome::default()) } /// JSON shape of a WAL Event record's payload (matches push.rs encoder). @@ -127,8 +256,9 @@ struct WalEventPayload { b: serde_json::Value, } -/// A single decoded v=2 record from the hand-rolled WAL file. -struct V2Record { +/// A single decoded record from the hand-rolled WAL file. +struct HandrolledWalRecord { + lsn: Lsn, body_format: u8, // reason: parsed from the v=2 record header for completeness; recovery // doesn't depend on the per-record registry version. @@ -139,29 +269,49 @@ struct V2Record { body: Vec, } -/// Parse all v=2 binary records from a contiguous byte slice. +/// Parse all hand-rolled binary records from a contiguous byte slice. /// -/// Format: `[u8 v=2][u8 body_format][u32 rv BE][u64 et_ms BE] -/// [u16 name_len BE][N bytes name][u32 body_len BE][M bytes body]` +/// v=2 format: +/// `[u8 v=2][u8 body_format][u32 rv BE][u64 et_ms BE] +/// [u16 name_len BE][N bytes name][u32 body_len BE][M bytes body]` /// -/// Stops at first byte that is not 0x02 (unknown version) or if bytes are +/// v=3 format: +/// `[u8 v=3][u64 assigned_lsn BE][u8 body_format][u32 rv BE][u64 et_ms BE] +/// [u16 name_len BE][N bytes name][u32 body_len BE][M bytes body]` +/// +/// Stops at first byte that is not 0x02/0x03 (unknown version) or if bytes are /// insufficient (truncated record — treat as EOF). -fn parse_v2_records(data: &[u8]) -> Vec { +fn parse_handrolled_records(data: &[u8], base_lsn: Lsn) -> Vec { let mut records = Vec::new(); let mut pos = 0usize; loop { - // Fixed header is 1+1+4+8+2 = 16 bytes. - if pos + 16 > data.len() { + if pos >= data.len() { break; } let version = data[pos]; - if version != 0x02 { + if version != 0x02 && version != 0x03 { break; } pos += 1; + let assigned_lsn = if version == 0x03 { + if pos + 8 > data.len() { + break; + } + let lsn = u64::from_be_bytes(data[pos..pos + 8].try_into().unwrap()); + pos += 8; + Some(lsn) + } else { + None + }; + + // Remaining fixed header is 1+4+8+2 = 15 bytes. + if pos + 15 > data.len() { + break; + } + let body_format = data[pos]; pos += 1; @@ -194,7 +344,8 @@ fn parse_v2_records(data: &[u8]) -> Vec { let body = data[pos..pos + body_len].to_vec(); pos += body_len; - records.push(V2Record { + records.push(HandrolledWalRecord { + lsn: assigned_lsn.unwrap_or_else(|| base_lsn.saturating_add(pos as u64)), body_format, rv, et_ms, @@ -209,17 +360,17 @@ fn parse_v2_records(data: &[u8]) -> Vec { /// Replay hand-rolled WAL files (`*.wal`) from `wal_dir`. /// /// Hand-rolled WAL files are written by `WalBufferRing` + `WalWriter` in the -/// v=2 binary record format (see `dispatch_push_sync` in `apply_shard`), +/// binary push-record format (see `dispatch_push_sync` in `apply_shard`), /// distinct from the `beava-persistence` `WalSink` format (`*.log`). Returns -/// recovery counters; assigns monotonic LSNs starting from `lsn_start`. +/// recovery counters and replays only records with `lsn > from_lsn_exclusive`. pub fn replay_handrolled_wal_dir( wal_dir: &Path, - lsn_start: Lsn, + from_lsn_exclusive: Lsn, dev_agg: &DevAggState, ) -> Result { use beava_core::wire::CT_MSGPACK; let mut outcome = RecoveryOutcome { - snapshot_lsn: lsn_start.saturating_sub(1), + snapshot_lsn: from_lsn_exclusive, ..Default::default() }; @@ -235,27 +386,42 @@ pub fn replay_handrolled_wal_dir( .collect(); wal_files.sort(); - let mut next_lsn = lsn_start; + let mut base_lsn = 0; for wal_file in &wal_files { let data = std::fs::read(wal_file)?; - let records = parse_v2_records(&data); + let records = parse_handrolled_records(&data, base_lsn); + base_lsn = base_lsn.saturating_add(data.len() as u64); for rec in records { - let lsn = next_lsn; - next_lsn += 1; + if rec.lsn <= from_lsn_exclusive { + continue; + } + outcome.last_lsn = outcome.last_lsn.max(rec.lsn); + + let quarantine_kind = if rec.body_format == CT_MSGPACK { + WalQuarantineKind::HandrolledMsgpackBody + } else { + WalQuarantineKind::HandrolledJsonBody + }; + if wal_quarantine_marker_exists(wal_dir, rec.lsn, quarantine_kind) { + outcome.quarantined_records += 1; + tracing::debug!( + target: "beava.recovery", + kind = "recovery.wal_quarantine_skip", + lsn = rec.lsn, + quarantine_kind = quarantine_kind.as_str(), + "skipping quarantined WAL record" + ); + continue; + } let row: Row = if rec.body_format == CT_MSGPACK { match rmp_serde::from_slice::(&rec.body) { Ok(r) => r, Err(e) => { - tracing::warn!( - target: "beava.recovery", - kind = "recovery.v2_msgpack_decode_failed", - lsn = lsn, - error = %e, - "v=2 msgpack body decode failed; skipping" - ); + quarantine_wal_decode_failure(wal_dir, rec.lsn, quarantine_kind, &e); + outcome.quarantined_records += 1; continue; } } @@ -263,13 +429,8 @@ pub fn replay_handrolled_wal_dir( match serde_json::from_slice::(&rec.body) { Ok(r) => r, Err(e) => { - tracing::warn!( - target: "beava.recovery", - kind = "recovery.v2_json_decode_failed", - lsn = lsn, - error = %e, - "v=2 JSON body decode failed; skipping" - ); + quarantine_wal_decode_failure(wal_dir, rec.lsn, quarantine_kind, &e); + outcome.quarantined_records += 1; continue; } } @@ -298,7 +459,7 @@ pub fn replay_handrolled_wal_dir( &rec.event_name, &row, rec.et_ms, - lsn, + rec.lsn, rec.rv as u64, &dev_agg.registry, &mut tables, @@ -306,14 +467,13 @@ pub fn replay_handrolled_wal_dir( ); } - dev_agg.next_event_id.fetch_max(lsn, Ordering::Relaxed); + dev_agg.next_event_id.fetch_max(rec.lsn, Ordering::Relaxed); if rec.et_ms > 0 { dev_agg .query_time_ms .fetch_max(rec.et_ms as u64, Ordering::Relaxed); } outcome.replay_event_count += 1; - outcome.last_lsn = lsn; } } @@ -340,22 +500,29 @@ pub fn replay_wal_from_lsn( } let records = WalReader::read_all(wal_dir)?; for rec in records { - if rec.lsn <= from_lsn_exclusive { - continue; - } - outcome.last_lsn = outcome.last_lsn.max(rec.lsn); match rec.record_type { RecordType::Event => { + if rec.lsn <= from_lsn_exclusive { + continue; + } + outcome.last_lsn = outcome.last_lsn.max(rec.lsn); + let quarantine_kind = WalQuarantineKind::PersistenceEventPayload; + if wal_quarantine_marker_exists(wal_dir, rec.lsn, quarantine_kind) { + outcome.quarantined_records += 1; + tracing::debug!( + target: "beava.recovery", + kind = "recovery.wal_quarantine_skip", + lsn = rec.lsn, + quarantine_kind = quarantine_kind.as_str(), + "skipping quarantined WAL record" + ); + continue; + } let payload: WalEventPayload = match serde_json::from_slice(&rec.payload) { Ok(p) => p, Err(e) => { - tracing::warn!( - target: "beava.recovery", - kind = "recovery.event_decode_failed", - lsn = rec.lsn, - error = %e, - "event payload decode failed; skipping" - ); + quarantine_wal_decode_failure(wal_dir, rec.lsn, quarantine_kind, &e); + outcome.quarantined_records += 1; continue; } }; @@ -389,27 +556,41 @@ pub fn replay_wal_from_lsn( outcome.replay_event_count += 1; } RecordType::RegistryBump => match RegistryBumpPayload::decode(&rec.payload) { - Ok(bump) => match crate::register::apply_registry_bump(&dev_agg.registry, bump) { - Ok(()) => { - outcome.replay_registry_bumps += 1; + Ok(bump) => { + outcome.last_lsn = outcome.last_lsn.max(rec.lsn); + if bump.new_version <= dev_agg.registry.version() { + continue; } - Err(e) => { - // Apply-after-fsync invariant: a durable RegistryBump - // that fails to apply is a hard recovery failure — - // silently skipping would let durable corruption hide. - tracing::error!( - target: "beava.recovery", - kind = "recovery.registry_bump_apply_failed", - lsn = rec.lsn, - error = %e, - "RegistryBump apply failed during replay" - ); - return Err(PersistError::Io(std::io::Error::other(format!( - "RegistryBump apply failed at LSN {}: {e}", - rec.lsn - )))); + match crate::register::apply_registry_bump(&dev_agg.registry, bump) { + Ok(()) => { + { + let mut tables = dev_agg.state_tables.lock(); + beava_core::agg_state_table::ensure_capacity_for( + &mut tables, + dev_agg.registry.next_agg_id() as usize, + ); + } + outcome.replay_registry_bumps += 1; + outcome.applied_registry_bump_after_snapshot = true; + } + Err(e) => { + // Apply-after-fsync invariant: a durable RegistryBump + // that fails to apply is a hard recovery failure — + // silently skipping would let durable corruption hide. + tracing::error!( + target: "beava.recovery", + kind = "recovery.registry_bump_apply_failed", + lsn = rec.lsn, + error = %e, + "RegistryBump apply failed during replay" + ); + return Err(PersistError::Io(std::io::Error::other(format!( + "RegistryBump apply failed at LSN {}: {e}", + rec.lsn + )))); + } } - }, + } Err(e) => { tracing::error!( target: "beava.recovery", @@ -433,6 +614,7 @@ pub fn replay_wal_from_lsn( snapshot_lsn = outcome.snapshot_lsn, events_replayed = outcome.replay_event_count, registry_bumps_replayed = outcome.replay_registry_bumps, + quarantined_records = outcome.quarantined_records, last_lsn = outcome.last_lsn, "recovery complete" ); @@ -463,3 +645,310 @@ fn json_object_to_row(jv: &serde_json::Value) -> Row { } row } + +#[cfg(test)] +mod tests { + use super::*; + use beava_core::agg_op::AggOp; + use beava_core::agg_state::CountState; + use beava_core::agg_state_table::{ensure_capacity_for, AggStateTable, EntityKey}; + use beava_core::registry::Registry; + use beava_persistence::{RecordType, SnapshotWriter, WalRecord}; + use compact_str::CompactString; + use serde_json::json; + use smallvec::smallvec; + use std::sync::Arc; + + fn txn_register_payload() -> crate::register::RegisterPayload { + serde_json::from_value(json!({ + "nodes": [ + { + "kind": "event", + "name": "Txn", + "schema": {"fields": { + "event_time": "i64", + "user_id": "str", + "amount": "f64" + }, "optional_fields": []} + }, + { + "kind": "derivation", + "name": "TxnAgg", + "output_kind": "table", + "upstreams": ["Txn"], + "ops": [{"op": "group_by", "keys": ["user_id"], "agg": { + "cnt": {"op": "count", "params": {}} + }}], + "schema": {"fields": {"user_id": "str", "cnt": "i64"}, "optional_fields": []}, + "table_primary_key": ["user_id"] + } + ] + })) + .expect("valid register payload") + } + + fn install_txn_registry(dev_agg: &DevAggState) { + let payload = txn_register_payload(); + let bump = crate::register::RegistryBumpPayload { + new_version: 1, + payload_nodes: payload.nodes, + force_removed_descriptors: Vec::new(), + }; + crate::register::apply_registry_bump(&dev_agg.registry, bump) + .expect("install txn registry"); + let mut tables = dev_agg.state_tables.lock(); + ensure_capacity_for(&mut tables, dev_agg.registry.next_agg_id() as usize); + } + + fn put_alice_count(dev_agg: &DevAggState, count: u64) { + let mut tables = dev_agg.state_tables.lock(); + ensure_capacity_for(&mut tables, 1); + let mut table = AggStateTable::new(); + let entity_key = EntityKey(smallvec![( + CompactString::from("user_id"), + Value::Str(CompactString::from("alice")), + )]); + table.insert_from_entity_key(entity_key, vec![AggOp::Count(CountState { n: count })]); + tables[0] = table; + } + + fn alice_count(dev_agg: &DevAggState) -> u64 { + let tables = dev_agg.state_tables.lock(); + let Some(ops) = tables + .first() + .and_then(|table| table.single_str.get("alice")) + else { + return 0; + }; + match ops.first() { + Some(AggOp::Count(count)) => count.n, + _ => 0, + } + } + + fn encode_handrolled_v3( + buf: &mut Vec, + lsn: Lsn, + body_format: u8, + rv: u32, + event_name: &str, + body: &[u8], + ) { + buf.push(0x03); + buf.extend_from_slice(&lsn.to_be_bytes()); + buf.push(body_format); + buf.extend_from_slice(&rv.to_be_bytes()); + buf.extend_from_slice(&(123i64).to_be_bytes()); + buf.extend_from_slice(&(event_name.len() as u16).to_be_bytes()); + buf.extend_from_slice(event_name.as_bytes()); + buf.extend_from_slice(&(body.len() as u32).to_be_bytes()); + buf.extend_from_slice(body); + } + + #[test] + fn handrolled_v3_records_use_persisted_lsn() { + let mut bytes = Vec::new(); + let body = br#"{"user_id":"alice","amount":1.0}"#; + let name = b"Txn"; + + bytes.push(0x03); + bytes.extend_from_slice(&10_000u64.to_be_bytes()); + bytes.push(beava_core::wire::CT_JSON); + bytes.extend_from_slice(&7u32.to_be_bytes()); + bytes.extend_from_slice(&(123i64).to_be_bytes()); + bytes.extend_from_slice(&(name.len() as u16).to_be_bytes()); + bytes.extend_from_slice(name); + bytes.extend_from_slice(&(body.len() as u32).to_be_bytes()); + bytes.extend_from_slice(body); + + let records = parse_handrolled_records(&bytes, 0); + assert_eq!(records.len(), 1); + assert_eq!(records[0].lsn, 10_000); + assert_eq!(records[0].rv, 7); + assert_eq!(records[0].event_name, "Txn"); + } + + #[test] + fn handrolled_decode_failure_writes_quarantine_marker() { + let wal = tempfile::tempdir().unwrap(); + let registry = Arc::new(Registry::new()); + let dev_agg = DevAggState::new(registry); + let lsn: Lsn = 379_827; + let body = b"not-json"; + let name = b"Txn"; + + let mut bytes = Vec::new(); + bytes.push(0x03); + bytes.extend_from_slice(&lsn.to_be_bytes()); + bytes.push(beava_core::wire::CT_JSON); + bytes.extend_from_slice(&1u32.to_be_bytes()); + bytes.extend_from_slice(&(123i64).to_be_bytes()); + bytes.extend_from_slice(&(name.len() as u16).to_be_bytes()); + bytes.extend_from_slice(name); + bytes.extend_from_slice(&(body.len() as u32).to_be_bytes()); + bytes.extend_from_slice(body); + std::fs::write(wal.path().join("wal-0000000000000000.wal"), bytes).unwrap(); + + let outcome = replay_handrolled_wal_dir(wal.path(), 0, &dev_agg).expect("replay"); + assert_eq!(outcome.last_lsn, lsn); + assert_eq!(outcome.replay_event_count, 0); + assert_eq!(outcome.quarantined_records, 1); + assert!(wal_quarantine_marker_exists( + wal.path(), + lsn, + WalQuarantineKind::HandrolledJsonBody + )); + + let outcome = replay_handrolled_wal_dir(wal.path(), 0, &dev_agg).expect("replay again"); + assert_eq!(outcome.last_lsn, lsn); + assert_eq!(outcome.quarantined_records, 1); + } + + #[test] + fn handrolled_msgpack_decode_failure_writes_quarantine_marker() { + let wal = tempfile::tempdir().unwrap(); + let registry = Arc::new(Registry::new()); + let dev_agg = DevAggState::new(registry); + let lsn: Lsn = 379_827; + + let mut bytes = Vec::new(); + encode_handrolled_v3( + &mut bytes, + lsn, + beava_core::wire::CT_MSGPACK, + 1, + "Txn", + &[0xc1], + ); + std::fs::write(wal.path().join("wal-0000000000000000.wal"), bytes).unwrap(); + + let outcome = replay_handrolled_wal_dir(wal.path(), 0, &dev_agg).expect("replay"); + assert_eq!(outcome.last_lsn, lsn); + assert_eq!(outcome.replay_event_count, 0); + assert_eq!(outcome.quarantined_records, 1); + assert!(wal_quarantine_marker_exists( + wal.path(), + lsn, + WalQuarantineKind::HandrolledMsgpackBody + )); + } + + #[test] + fn snapshot_load_body_applied_lsn_gates_handrolled_replay() { + let wal = tempfile::tempdir().unwrap(); + let snap = tempfile::tempdir().unwrap(); + let registry = Arc::new(Registry::new()); + let dev_agg = DevAggState::new(registry); + + install_txn_registry(&dev_agg); + put_alice_count(&dev_agg, 1); + dev_agg.next_event_id.store(100, Ordering::Relaxed); + + let body = { + let registry_snap = dev_agg.registry.snapshot(); + let tables = dev_agg.state_tables.lock(); + SnapshotBody::from_live(®istry_snap, &tables, 100, 123) + }; + let encoded = body.encode().expect("encode snapshot"); + SnapshotWriter::write_with_stats(snap.path(), 5, body.registry.version, &encoded) + .expect("write snapshot with older header LSN"); + + let mut wal_bytes = Vec::new(); + encode_handrolled_v3( + &mut wal_bytes, + 90, + beava_core::wire::CT_JSON, + dev_agg.registry.version() as u32, + "Txn", + br#"{"user_id":"alice","amount":1.0}"#, + ); + std::fs::write(wal.path().join("wal-0000000000000000.wal"), wal_bytes).unwrap(); + + let registry = Arc::new(Registry::new()); + let recovered = DevAggState::new(registry); + let loaded = load_snapshot_if_any(snap.path(), &recovered).expect("load snapshot"); + assert_eq!(loaded.snapshot_lsn, 5); + assert_eq!(loaded.applied_lsn, 100); + assert_eq!(alice_count(&recovered), 1); + + let replay = + replay_handrolled_wal_dir(wal.path(), loaded.applied_lsn, &recovered).expect("replay"); + assert_eq!(replay.replay_event_count, 0); + assert_eq!( + alice_count(&recovered), + 1, + "using the snapshot body watermark must not double-apply covered v3 WAL records" + ); + } + + #[test] + fn persistence_event_decode_failure_writes_quarantine_marker() { + let wal = tempfile::tempdir().unwrap(); + let registry = Arc::new(Registry::new()); + let dev_agg = DevAggState::new(registry); + let lsn: Lsn = 379_827; + + let mut writer = + beava_persistence::WalWriter::open(wal.path(), 100, dev_agg.registry.version() as u32) + .expect("open wal writer"); + writer + .append(&WalRecord { + lsn, + record_type: RecordType::Event, + payload: b"not-json".to_vec(), + }) + .expect("append event"); + writer.sync_data().expect("sync wal"); + drop(writer); + + let outcome = replay_wal_from_lsn(wal.path(), 0, &dev_agg).expect("replay wal"); + assert_eq!(outcome.last_lsn, lsn); + assert_eq!(outcome.replay_event_count, 0); + assert_eq!(outcome.quarantined_records, 1); + assert!(wal_quarantine_marker_exists( + wal.path(), + lsn, + WalQuarantineKind::PersistenceEventPayload + )); + + let outcome = replay_wal_from_lsn(wal.path(), 0, &dev_agg).expect("replay wal again"); + assert_eq!(outcome.last_lsn, lsn); + assert_eq!(outcome.quarantined_records, 1); + } + + #[test] + fn replay_skips_already_installed_registry_bump_even_past_snapshot_lsn() { + let wal = tempfile::tempdir().unwrap(); + let registry = Arc::new(Registry::new()); + let dev_agg = DevAggState::new(registry); + let payload = txn_register_payload(); + let bump = crate::register::RegistryBumpPayload { + new_version: 1, + payload_nodes: payload.nodes, + force_removed_descriptors: Vec::new(), + }; + + crate::register::apply_registry_bump(&dev_agg.registry, bump.clone()) + .expect("install bump before replay"); + assert_eq!(dev_agg.registry.version(), 1); + + let mut writer = + beava_persistence::WalWriter::open(wal.path(), 100, dev_agg.registry.version() as u32) + .expect("open wal writer"); + writer + .append(&WalRecord { + lsn: 123, + record_type: RecordType::RegistryBump, + payload: bump.encode().expect("encode bump"), + }) + .expect("append bump"); + writer.sync_data().expect("sync wal"); + drop(writer); + + let outcome = replay_wal_from_lsn(wal.path(), 42, &dev_agg).expect("replay wal"); + assert_eq!(outcome.last_lsn, 123); + assert_eq!(outcome.replay_registry_bumps, 0); + assert!(!outcome.applied_registry_bump_after_snapshot); + assert_eq!(dev_agg.registry.version(), 1); + } +} diff --git a/crates/beava-server/src/register.rs b/crates/beava-server/src/register.rs index c22a2193..74fd3d47 100644 --- a/crates/beava-server/src/register.rs +++ b/crates/beava-server/src/register.rs @@ -5,10 +5,9 @@ //! 2. JSON parse → 400 //! 3. Snapshot current registry for validation + diff //! 4. validate_payload → 400 -//! 5. classify_register_diff (apply_shard's pre-flight has already -//! pre-removed any descriptor whose shape would change with force=true, -//! or returned 409 force_required without force; destructive entries -//! here are an invariant violation → 503) +//! 5. classify_register_diff (apply_shard's pre-flight has either returned +//! 409 force_required without force, or supplied the force-removal set +//! that this module persists in the RegistryBump before applying) //! 6. No-op (no NewDescriptor entries in additive) → 200 same version //! 7. Additive install → 200 new version @@ -222,8 +221,16 @@ pub(crate) async fn execute_register_with_wal( payload: RegisterPayload, wal_sink: &WalSink, force_removed: Vec, + wal_min_lsn: u64, ) -> RegisterOutcome { - execute_register_inner(registry, payload, Some(wal_sink), force_removed).await + execute_register_inner( + registry, + payload, + Some(wal_sink), + force_removed, + wal_min_lsn, + ) + .await } async fn execute_register_inner( @@ -231,6 +238,7 @@ async fn execute_register_inner( payload: RegisterPayload, wal_sink: Option<&WalSink>, force_removed: Vec, + wal_min_lsn: u64, ) -> RegisterOutcome { if payload.nodes.is_empty() { let version = registry.version(); @@ -273,46 +281,45 @@ async fn execute_register_inner( let registered_descriptors: Vec = nodes.iter().map(|n| n.name().to_string()).collect(); // Use the new (Phase 13.4 Plan 06) categorized diff. apply_shard's - // force-handling block pre-removes every existing descriptor the - // payload would change (destructive + additive-against-existing, - // when force=true) BEFORE this function runs. By the time we get - // here, classify against the post-pre-removal snapshot should never - // produce destructive entries — every remaining diff is additive - // (NewDescriptor) or already_present (exact match). + // force-handling block computes every existing descriptor the payload + // would replace (destructive + additive-against-existing) but does not + // mutate the live registry before the WAL append. By the time we apply + // below, the removal list is carried in the durable RegistryBump. let diff = beava_core::register_validate::classify_register_diff(¤t_snapshot, &nodes); - // Invariant check: apply_shard's force-handling block pre-removes every - // descriptor whose shape would change before this function is called. - // If destructive entries reach here, the caller bypassed apply_shard - // (or its pre-flight has a bug) — surface as WalUnavailable (503) so - // operators see a noisy server-side error rather than a silent no-op. - if !diff.destructive.is_empty() { + // Invariant check: destructive entries are allowed only when apply_shard + // supplied the force-removal set that will be applied after fsync. + if !diff.destructive.is_empty() && force_removed.is_empty() { warn!( kind = "register.preflight_invariant_violated", version = current_snapshot.version, destructive = ?diff.destructive, - "execute_register saw destructive entries — apply_shard pre-flight should have pre-removed them; refusing to mutate" + "execute_register saw destructive entries without a force-removal set; refusing to mutate" ); return RegisterOutcome::WalUnavailable { version: current_snapshot.version, }; } - // Net-new descriptors are entries with `kind: new_descriptor`. Other - // additive variants (NewField, NewAgg) shouldn't appear here in normal - // flow — apply_shard pre-removes their target descriptor with - // force=true so they re-land here as NewDescriptor against the - // post-removal snapshot. - let added: Vec = diff - .additive - .iter() - .filter_map(|e| match e { - beava_core::registry_diff::DiffEntry::NewDescriptor { name, .. } => Some(name.clone()), - _ => None, - }) - .collect(); + // Net-new descriptors are entries with `kind: new_descriptor`. With + // force=true, apply_shard supplies the descriptor-removal set and the + // durable RegistryBump applies it before re-installing the payload, so + // every registered descriptor is reported as added. + let added: Vec = if force_removed.is_empty() { + diff.additive + .iter() + .filter_map(|e| match e { + beava_core::registry_diff::DiffEntry::NewDescriptor { name, .. } => { + Some(name.clone()) + } + _ => None, + }) + .collect() + } else { + registered_descriptors.clone() + }; - if added.is_empty() { + if added.is_empty() && force_removed.is_empty() { info!( kind = "register.noop", version = current_snapshot.version, @@ -326,15 +333,16 @@ async fn execute_register_inner( }; } + let bump = RegistryBumpPayload { + new_version: current_snapshot.version + 1, + payload_nodes: nodes.clone(), + force_removed_descriptors: force_removed.clone(), + }; + // Apply-after-fsync: append + fsync the `RegistryBump` BEFORE mutating // the live registry, so recovery only sees descriptors that survived // the durability boundary. if let Some(sink) = wal_sink { - let bump = RegistryBumpPayload { - new_version: current_snapshot.version + 1, - payload_nodes: nodes.clone(), - force_removed_descriptors: force_removed.clone(), - }; let encoded = match bump.encode() { Ok(b) => b, Err(e) => { @@ -348,7 +356,10 @@ async fn execute_register_inner( }; } }; - if let Err(e) = sink.append_record(RecordType::RegistryBump, encoded).await { + if let Err(e) = sink + .append_record_at_least(RecordType::RegistryBump, encoded, wal_min_lsn) + .await + { warn!( kind = "register.wal_append_failed", error = %e, @@ -360,12 +371,28 @@ async fn execute_register_inner( } } - let new_version = registry.apply_registration( - nodes, - compiled_chains, - propagated_schemas, - compiled_aggregations, - ); + let new_version = if force_removed.is_empty() { + registry.apply_registration( + nodes, + compiled_chains, + propagated_schemas, + compiled_aggregations, + ) + } else { + match crate::register::apply_registry_bump(registry, bump) { + Ok(()) => registry.version(), + Err(e) => { + warn!( + kind = "register.force_apply_failed_after_wal", + error = %e, + "force RegistryBump apply failed after WAL append" + ); + return RegisterOutcome::WalUnavailable { + version: current_snapshot.version, + }; + } + } + }; info!( kind = "register.success", version = new_version, @@ -526,3 +553,151 @@ pub(crate) fn error_code_to_wire_str(code: ErrorCode) -> &'static str { pub fn format_serde_error_public(e: &serde_json::Error) -> (String, String) { ("".to_string(), e.to_string()) } + +#[cfg(test)] +mod tests { + use super::*; + use beava_core::registry::Registry; + use serde_json::json; + use std::sync::Arc; + + fn baseline_payload() -> RegisterPayload { + serde_json::from_value(json!({ + "nodes": [ + { + "kind": "event", + "name": "Tx", + "schema": { + "fields": { + "event_time": "i64", + "user_id": "str", + "amount": "f64" + }, + "optional_fields": [] + } + }, + { + "kind": "derivation", + "name": "UserSpend", + "output_kind": "event", + "upstreams": ["Tx"], + "ops": [{ + "op": "group_by", + "keys": ["user_id"], + "agg": { + "cnt": {"op": "count", "params": {"window": "1h"}}, + "total": {"op": "sum", "params": {"field": "amount", "window": "1h"}} + } + }], + "schema": { + "fields": {"user_id": "str", "cnt": "i64", "total": "f64"}, + "optional_fields": [] + } + } + ] + })) + .expect("valid baseline register payload") + } + + fn changed_window_payload() -> RegisterPayload { + serde_json::from_value(json!({ + "nodes": [ + { + "kind": "event", + "name": "Tx", + "schema": { + "fields": { + "event_time": "i64", + "user_id": "str", + "amount": "f64" + }, + "optional_fields": [] + } + }, + { + "kind": "derivation", + "name": "UserSpend", + "output_kind": "event", + "upstreams": ["Tx"], + "ops": [{ + "op": "group_by", + "keys": ["user_id"], + "agg": { + "cnt": {"op": "count", "params": {"window": "30m"}}, + "total": {"op": "sum", "params": {"field": "amount", "window": "30m"}} + } + }], + "schema": { + "fields": {"user_id": "str", "cnt": "i64", "total": "f64"}, + "optional_fields": [] + } + } + ] + })) + .expect("valid changed-window register payload") + } + + #[tokio::test(flavor = "current_thread")] + async fn force_register_wal_failure_does_not_mutate_registry() { + let registry = Arc::new(Registry::new()); + apply_registry_bump( + ®istry, + RegistryBumpPayload { + new_version: 1, + payload_nodes: baseline_payload().nodes, + force_removed_descriptors: Vec::new(), + }, + ) + .expect("install baseline"); + + let before = registry.snapshot(); + assert_eq!(before.version, 1); + assert!(before.events.contains_key("Tx")); + assert!(before.derivations.contains_key("UserSpend")); + assert!(before.compiled_aggregations.contains_key("UserSpend")); + assert_eq!( + registry + .compiled_aggregation("UserSpend") + .expect("baseline agg") + .features + .iter() + .find(|f| f.feature_name == "cnt") + .and_then(|f| f.descriptor.window_ms), + Some(3_600_000) + ); + + let (sink, handle) = beava_persistence::WalSink::spawn_no_op(); + sink.clone().shutdown().await.expect("shutdown no-op sink"); + handle.await.expect("join no-op sink"); + + let outcome = execute_register_with_wal( + ®istry, + changed_window_payload(), + &sink, + vec!["UserSpend".to_string()], + 2, + ) + .await; + let (status, body) = map_outcome_to_response(outcome); + assert_eq!(status, 503); + assert_eq!(body["error"]["code"], "wal_unavailable"); + assert_eq!(body["registry_version"], 1); + + let after = registry.snapshot(); + assert_eq!(after.version, before.version); + assert!(after.events.contains_key("Tx")); + assert!(after.derivations.contains_key("UserSpend")); + assert!(after.compiled_aggregations.contains_key("UserSpend")); + assert_eq!( + registry + .compiled_aggregation("UserSpend") + .expect("agg survives WAL failure") + .features + .iter() + .find(|f| f.feature_name == "cnt") + .and_then(|f| f.descriptor.window_ms), + Some(3_600_000), + "force removal must not apply before the RegistryBump is durable" + ); + } +} diff --git a/crates/beava-server/src/server.rs b/crates/beava-server/src/server.rs index 6b4ae137..f5e8a56c 100644 --- a/crates/beava-server/src/server.rs +++ b/crates/beava-server/src/server.rs @@ -287,6 +287,7 @@ struct ServerV18State { wal_ring: Arc, wal_lsn: Arc, wal_writer_handle: std::thread::JoinHandle<()>, + wal_reclaim: Option, /// TCP frame-size cap plumbed through `WorkerConfig` rather than read /// from env per-frame, so parallel `TestServer` instances don't /// contaminate each other. @@ -322,6 +323,12 @@ impl ServerV18 { tcp_addr: std::net::SocketAddr, admin_addr: std::net::SocketAddr, ) -> Result { + // Opt this process out of Transparent Huge Pages (Linux), warn if + // the system default is `[always]`. THP makes fork()-snapshot COW + // granularity 2 MB instead of 4 KB — a 500× amplifier on COW + // memory overhead during BGSAVE-style work. See crate::thp. + crate::thp::detect_and_opt_out(); + // Bind event-plane listeners (std::net — they'll be handed to mio later). let http_listener = std::net::TcpListener::bind(http_addr).map_err(|e| ServerError::Bind { @@ -769,8 +776,7 @@ async fn build_runtime_state_with_persistence( // 2. Replay `*.log` records with `lsn > snapshot_lsn` (RegistryBumps // and any persistence-WAL events from the legacy `WalSink` // path). - // 3. Replay `*.wal` data-plane events (v=2 binary format from - // `apply_shard`). + // 3. Replay `*.wal` data-plane events from `apply_shard`. // Memory mode skips this whole block — state starts fresh. let initial_start_lsn = if is_memory { tracing::info!( @@ -780,29 +786,34 @@ async fn build_runtime_state_with_persistence( ); 1 } else { - let snapshot_lsn = crate::recovery::load_snapshot_if_any(&snapshot_dir, &dev_agg) + let snapshot_load = crate::recovery::load_snapshot_if_any(&snapshot_dir, &dev_agg) .ok() - .unwrap_or(0); + .unwrap_or_default(); + let snapshot_lsn = snapshot_load.snapshot_lsn; let persistence_lsn = if wal_dir.exists() { match replay_wal_from_lsn(&wal_dir, snapshot_lsn, &dev_agg) { - Ok(outcome) => outcome.last_lsn, + Ok(outcome) => outcome.last_lsn.max(snapshot_lsn), Err(_) => snapshot_lsn, } } else { snapshot_lsn }; - // Replay hand-rolled `*.wal` data-plane events. Setting - // `lsn_start = persistence_lsn + 1` keeps LSNs monotonic across - // the snapshot, persistence, and hand-rolled paths. - let handrolled_lsn_start = persistence_lsn + 1; + // Replay hand-rolled `*.wal` data-plane events past the state already + // covered by the snapshot body. The snapshot header LSN is a mixed + // legacy/data-plane checkpoint; older snapshots can have a header LSN + // lower than their serialized data-plane state, and registry `.log` + // records can have higher LSNs than post-snapshot data-plane records. + // The body watermark is the only safe floor for hand-rolled replay. + let handrolled_from_lsn = snapshot_load.applied_lsn; let handrolled_outcome = - replay_handrolled_wal_dir(&wal_dir, handrolled_lsn_start, &dev_agg).unwrap_or_default(); + replay_handrolled_wal_dir(&wal_dir, handrolled_from_lsn, &dev_agg).unwrap_or_default(); let initial = handrolled_outcome .last_lsn .max(persistence_lsn) .max(snapshot_lsn) + .max(snapshot_load.applied_lsn) + 1; tracing::debug!( @@ -866,7 +877,7 @@ async fn build_runtime_state_with_persistence( ); } - let wal_lsn = Arc::new(WalLsn::new()); + let wal_lsn = Arc::new(WalLsn::new_at(initial_start_lsn.saturating_sub(1))); // Resolve WAL config from explicit overrides — hot path never reads // env. Production resolves from `ServerV18Config::from_env()` at // boot; tests pass explicit values via `TestServerBuilder`. The @@ -893,8 +904,10 @@ async fn build_runtime_state_with_persistence( // fsync. Memory mode: drain sealed buffers back to the free pool // with no file I/O so the apply hot path can't backpressure-block // once buffers fill. - let (wal_writer_shutdown, wal_writer_handle) = if is_memory { - spawn_no_op_wal_writer(Arc::clone(&wal_ring), Arc::clone(&wal_lsn), wal_cfg.tick_ms) + let (wal_writer_shutdown, wal_writer_handle, wal_reclaim) = if is_memory { + let (shutdown, handle) = + spawn_no_op_wal_writer(Arc::clone(&wal_ring), Arc::clone(&wal_lsn), wal_cfg.tick_ms); + (shutdown, handle, None) } else { let wal_writer = WalWriter::new( &wal_dir, @@ -903,13 +916,14 @@ async fn build_runtime_state_with_persistence( wal_cfg.tick_ms, ) .map_err(|e| ServerError::WalSpawn(e.to_string()))?; + let reclaim = wal_writer.reclaim_handle(); // Capture the shutdown flag BEFORE `spawn()` consumes the writer. // Without it, the writer loop would never see the shutdown signal // and `JoinHandle` drop would detach the thread mid-tick, losing // any active-buffer contents that hadn't been sealed yet. let shutdown = wal_writer.shutdown_flag(); let handle = wal_writer.spawn(); - (shutdown, handle) + (shutdown, handle, Some(reclaim)) }; // Memory mode skips the snapshot task entirely (zero file I/O), but @@ -932,9 +946,16 @@ async fn build_runtime_state_with_persistence( interval: Duration::from_millis(snapshot_interval_ms.max(1)), snapshot_dir: snapshot_dir.clone(), retain: 2, + // Read env once at boot — these are the SOLE legitimate + // env-read sites. Tests pass config fields directly per + // `phase13_5_3_no_env_var_pokes_in_tests`. + min_events_per_snapshot: crate::snapshot_task::min_events_from_env(), + use_fork_snapshot: crate::snapshot_fork::fork_enabled(), + snapshot_lsn_capture_tx: None, }, Arc::clone(&app_state), wal_sink.clone(), + wal_reclaim.clone(), snapshot_cancel.clone(), ); (Some((snapshot_cancel, snapshot_worker)), snapshot_trigger) @@ -949,6 +970,7 @@ async fn build_runtime_state_with_persistence( wal_ring, wal_lsn, wal_writer_handle, + wal_reclaim, wal_writer_shutdown, snapshot_task, snapshot_trigger, @@ -1042,6 +1064,7 @@ where wal_ring, wal_lsn, wal_writer_handle, + wal_reclaim: _wal_reclaim, wal_writer_shutdown, snapshot_task, snapshot_trigger, diff --git a/crates/beava-server/src/snapshot_fork.rs b/crates/beava-server/src/snapshot_fork.rs new file mode 100644 index 00000000..8e4c1e89 --- /dev/null +++ b/crates/beava-server/src/snapshot_fork.rs @@ -0,0 +1,606 @@ +//! fork()+COW snapshot path — Valkey BGSAVE pattern adapted for beava. +//! +//! The parent acquires `state_tables.lock()` across the `fork()` syscall, then +//! immediately releases it in the parent. The child inherits the held guard and +//! reads through that guard without taking any new `parking_lot` locks. Apply- +//! thread blocking drops from ~seconds to the fork syscall window. +//! +//! Default ON on unix (linux/macos). Set `BEAVA_SNAPSHOT_FORK=0` (or +//! `false`/`no`) to opt back into the legacy in-process synchronous +//! snapshot in `snapshot_task::do_snapshot`. On non-unix targets the +//! fork path is unavailable and the in-process path is always used. +//! +//! ## Safety / fork-correctness notes +//! +//! The single `unsafe { libc::fork() }` call has these invariants: +//! +//! 1. **beava's tokio runtime is `new_current_thread`** (see +//! `crates/beava-server/src/main.rs` + `quickstart.rs`). Total OS threads +//! at fork time = the tokio main thread + the mio apply thread + the +//! `beava-wal-writer-noop` tick thread + possibly a `spawn_blocking` +//! worker. The forking thread is the tokio main thread (it runs +//! `snapshot_task`). All other threads vanish in the child. +//! +//! 2. **Allocator is fork-safe.** beava uses the system allocator (glibc on +//! Linux, libc on macOS). Both have `pthread_atfork` malloc handlers that +//! take the malloc lock pre-fork and release it post-fork in both +//! parent and child. `bincode::serialize` in the child therefore allocates +//! safely. +//! +//! 3. **Locks held by vanished threads are irrelevant.** The parent captures +//! the registry snapshot before `fork()`, so the child never takes the +//! registry `RwLock` in its inherited address space. The child only +//! touches: `app_state.dev_agg.state_tables` (read-only via the lock guard +//! the forking thread holds), scalar counter copies captured pre-fork, and +//! `std::fs` (writes the new snapshot file via its own fds). It does NOT +//! touch WAL state, tokio runtime, the admin sidecar, or any +//! `parking_lot::Mutex` it didn't already hold at fork time. +//! +//! 4. **Child never returns; calls `libc::_exit`.** `_exit` is async-signal- +//! safe and skips Rust destructors / atexit handlers / tokio shutdown +//! that could touch parent state. `std::process::exit` would run atexit +//! handlers — unsafe in a forked child. +//! +//! 5. **Child error reporting via sidecar file.** Child writes +//! `snapshot-.error` on failure, then `_exit(1)`. Parent reads this +//! after `waitpid`. + +use crate::AppState; +use beava_core::snapshot_body::SnapshotBody; +use beava_persistence::{PersistError, SnapshotWriteStats}; +use std::path::{Path, PathBuf}; +use std::sync::atomic::Ordering; +#[cfg(unix)] +use std::time::{Duration, Instant}; + +/// Result of a fork-snapshot. The parent uses `ChildExit::Success` to decide +/// whether to truncate the WAL. +#[derive(Debug)] +pub enum ChildExit { + /// Child exited with status 0 — snapshot file is durable. + Success { + snapshot_lsn: u64, + write_stats: Option, + }, + /// Child exited non-zero or with a signal. Snapshot file may be partial + /// or absent. + Failure { code: i32, message: String }, +} + +#[derive(Debug, thiserror::Error)] +pub enum SnapshotForkError { + #[error("fork(2) failed: {0}")] + ForkFailed(std::io::Error), + #[error("child waitpid failed: {0}")] + WaitFailed(std::io::Error), + #[error("persistence: {0}")] + Persist(#[from] PersistError), +} + +/// Whether the fork path is enabled. Default ON on unix (linux/macos); +/// callers can opt out by setting `BEAVA_SNAPSHOT_FORK` to `0`, `false`, +/// `no`, or empty. Any other value (or unset) keeps the fork path on. +/// Reads the env on every call (cold path; cost is negligible vs. a +/// snapshot cycle). Always `false` on non-unix targets — fork(2) is +/// unavailable there. +pub fn fork_enabled() -> bool { + if !cfg!(unix) { + return false; + } + !matches!( + std::env::var("BEAVA_SNAPSHOT_FORK").as_deref(), + Ok("0") | Ok("false") | Ok("FALSE") | Ok("no") | Ok("") + ) +} + +/// Perform a snapshot via `fork()` + COW. Returns the child's exit summary +/// so the caller can gate WAL reclamation on success. +/// +/// The caller is responsible for: +/// - Passing the legacy `WalSink` LSN. This function combines it with the +/// applied data-plane watermark while holding `state_tables.lock()`, so the +/// snapshot LSN matches the state snapshot the child inherits. +/// - Truncating the WAL up to `snapshot_lsn` only on `ChildExit::Success`. +/// +/// `snapshot_dir` must exist (the in-process path creates it lazily; the +/// child cannot afford a directory-creation failure mid-flight). Caller +/// should `std::fs::create_dir_all(snapshot_dir)` before this call. +#[cfg(unix)] +pub async fn do_snapshot_via_fork( + snapshot_dir: &Path, + legacy_snapshot_lsn: u64, + app_state: &AppState, +) -> Result { + do_snapshot_via_fork_with_wait_timeout( + snapshot_dir, + legacy_snapshot_lsn, + app_state, + snapshot_fork_wait_timeout(), + ) + .await +} + +#[cfg(unix)] +pub async fn do_snapshot_via_fork_with_wait_timeout( + snapshot_dir: &Path, + legacy_snapshot_lsn: u64, + app_state: &AppState, + wait_timeout: Duration, +) -> Result { + use beava_persistence::SnapshotWriter; + + // Ensure the snapshot dir exists in the parent (cheap; idempotent). The + // child cannot afford a mkdir failure. + std::fs::create_dir_all(snapshot_dir) + .map_err(|e| SnapshotForkError::Persist(PersistError::Io(e)))?; + + let snapshot_dir_owned = snapshot_dir.to_path_buf(); + let registry_snap = app_state.dev_agg.registry.snapshot(); + + let (state_lock, next_event_id, query_time_ms, snapshot_lsn) = loop { + let candidate_next_event_id = app_state.dev_agg.next_event_id.load(Ordering::Acquire); + let candidate_snapshot_lsn = legacy_snapshot_lsn.max(candidate_next_event_id); + let _ = std::fs::remove_file(snapshot_stats_sidecar_path( + snapshot_dir, + candidate_snapshot_lsn, + )); + let _ = std::fs::remove_file(snapshot_error_sidecar_path( + snapshot_dir, + candidate_snapshot_lsn, + )); + + let state_lock = app_state.dev_agg.state_tables.lock(); + let next_event_id = app_state.dev_agg.next_event_id.load(Ordering::Acquire); + let query_time_ms = app_state.dev_agg.query_time_ms.load(Ordering::Acquire) as i64; + let snapshot_lsn = legacy_snapshot_lsn.max(next_event_id); + if snapshot_lsn == candidate_snapshot_lsn { + break (state_lock, next_event_id, query_time_ms, snapshot_lsn); + } + drop(state_lock); + }; + + // Briefly take the state_tables lock so the fork sees a quiescent state + // snapshot. The lock-hold spans two scalar loads plus the fork syscall + // (~µs); path setup, registry capture, and sidecar cleanup happened above. + // + // SAFETY: + // - beava's tokio runtime is `new_current_thread`; the forking thread is + // the tokio main thread. All other OS threads (mio apply, wal-writer- + // noop, spawn_blocking workers) vanish in the child per POSIX. + // - System malloc (glibc/libc) is fork-safe via pthread_atfork handlers, + // so `bincode::serialize` in the child allocates safely. + // - Child uses the pre-captured registry snapshot and the inherited + // `state_lock` guard; it takes no registry RwLock, no parking_lot Mutex, + // no tokio, no WAL, no admin sidecar. + // - Child calls `libc::_exit` (async-signal-safe; skips at_exit + // handlers) rather than `std::process::exit`. + let pid = unsafe { libc::fork() }; + + if pid < 0 { + return Err(SnapshotForkError::ForkFailed( + std::io::Error::last_os_error(), + )); + } + + if pid == 0 { + // === CHILD === + // Build snapshot from our (now-frozen via COW) view of app_state. + // Do not lock or unlock `state_tables` in the child. The forking + // thread already held this guard, and `_exit` skips its destructor. + let body = + SnapshotBody::from_live(®istry_snap, &state_lock, next_event_id, query_time_ms); + + let encoded = match body.encode() { + Ok(b) => b, + Err(e) => child_fail(&snapshot_dir_owned, snapshot_lsn, &format!("encode: {e}")), + }; + let registry_version = body.registry.version; + + match SnapshotWriter::write_with_stats( + &snapshot_dir_owned, + snapshot_lsn, + registry_version, + &encoded, + ) { + Ok(stats) => { + if let Err(e) = write_stats_sidecar(&snapshot_dir_owned, snapshot_lsn, &stats) { + child_fail(&snapshot_dir_owned, snapshot_lsn, &format!("stats: {e}")); + } + unsafe { + libc::_exit(0); + } + } + Err(e) => child_fail(&snapshot_dir_owned, snapshot_lsn, &format!("write: {e}")), + } + } + + // === PARENT === + drop(state_lock); + + // Wait on the child without blocking the tokio runtime. The blocking side + // polls with WNOHANG so a wedged fork child can be killed and reaped instead + // of leaving an uncancelable waitpid task behind. + let exit = tokio::task::spawn_blocking(move || { + wait_for_snapshot_child(pid, snapshot_dir_owned, snapshot_lsn, wait_timeout) + }) + .await + .map_err(|e| SnapshotForkError::WaitFailed(std::io::Error::other(format!("join: {e}"))))? + .map_err(SnapshotForkError::WaitFailed)?; + + Ok(exit) +} + +#[cfg(unix)] +const DEFAULT_SNAPSHOT_FORK_WAIT_TIMEOUT_SECS: u64 = 600; + +#[cfg(unix)] +fn snapshot_fork_wait_timeout() -> Duration { + std::env::var("BEAVA_SNAPSHOT_FORK_WAIT_TIMEOUT_SECS") + .ok() + .and_then(|raw| raw.parse::().ok()) + .filter(|secs| *secs > 0) + .map(Duration::from_secs) + .unwrap_or_else(|| Duration::from_secs(DEFAULT_SNAPSHOT_FORK_WAIT_TIMEOUT_SECS)) +} + +#[cfg(unix)] +fn wait_for_snapshot_child( + pid: libc::pid_t, + snapshot_dir: PathBuf, + snapshot_lsn: u64, + timeout: Duration, +) -> Result { + let deadline = Instant::now() + timeout; + loop { + let mut status: libc::c_int = 0; + let waited = unsafe { libc::waitpid(pid, &mut status, libc::WNOHANG) }; + if waited == pid { + return Ok(child_exit_from_status(status, &snapshot_dir, snapshot_lsn)); + } + if waited < 0 { + let err = std::io::Error::last_os_error(); + if err.raw_os_error() == Some(libc::EINTR) { + if Instant::now() >= deadline { + return terminate_timed_out_child(pid, timeout); + } + continue; + } + return Err(err); + } + + if Instant::now() >= deadline { + return terminate_timed_out_child(pid, timeout); + } + + std::thread::sleep(Duration::from_millis(10)); + } +} + +#[cfg(unix)] +fn terminate_timed_out_child( + pid: libc::pid_t, + timeout: Duration, +) -> Result { + let kill_error = if unsafe { libc::kill(pid, libc::SIGKILL) } == 0 { + None + } else { + Some(std::io::Error::last_os_error()) + }; + let reap_grace = Duration::from_secs(1); + let reap_deadline = Instant::now() + reap_grace; + let reaped = reap_child_until(pid, reap_deadline)?; + + let mut message = format!( + "child exceeded fork snapshot wait timeout of {}s and was killed", + timeout.as_secs() + ); + if let Some(err) = kill_error { + message.push_str(&format!("; SIGKILL failed: {err}")); + } + + match reaped { + Some(status) => { + if libc::WIFSIGNALED(status) { + message.push_str(&format!("; reaped signal {}", libc::WTERMSIG(status))); + } else if libc::WIFEXITED(status) { + message.push_str(&format!( + "; reaped exit status {}", + libc::WEXITSTATUS(status) + )); + } else { + message.push_str(&format!("; reaped status {status}")); + } + Ok(ChildExit::Failure { code: -1, message }) + } + None => Err(std::io::Error::new( + std::io::ErrorKind::TimedOut, + format!( + "child exceeded fork snapshot wait timeout of {}s, but was not reaped within {}ms", + timeout.as_secs(), + reap_grace.as_millis() + ), + )), + } +} + +#[cfg(unix)] +fn reap_child_until( + pid: libc::pid_t, + deadline: Instant, +) -> Result, std::io::Error> { + loop { + let mut status: libc::c_int = 0; + let waited = unsafe { libc::waitpid(pid, &mut status, libc::WNOHANG) }; + if waited == pid { + return Ok(Some(status)); + } + if waited < 0 { + let err = std::io::Error::last_os_error(); + if err.raw_os_error() == Some(libc::EINTR) { + if Instant::now() >= deadline { + return Ok(None); + } + continue; + } + return Err(err); + } + if Instant::now() >= deadline { + return Ok(None); + } + std::thread::sleep(Duration::from_millis(10)); + } +} + +#[cfg(unix)] +fn child_exit_from_status( + status: libc::c_int, + snapshot_dir: &Path, + snapshot_lsn: u64, +) -> ChildExit { + if libc::WIFEXITED(status) { + let code = libc::WEXITSTATUS(status); + if code == 0 { + match read_stats_sidecar(snapshot_dir, snapshot_lsn) { + Some(write_stats) => ChildExit::Success { + snapshot_lsn, + write_stats: Some(write_stats), + }, + None => ChildExit::Failure { + code, + message: format!( + "child exited successfully but stats sidecar was missing or corrupt for snapshot LSN {snapshot_lsn}" + ), + }, + } + } else { + let err_path = snapshot_error_sidecar_path(snapshot_dir, snapshot_lsn); + let message = std::fs::read_to_string(&err_path) + .unwrap_or_else(|_| format!("child exited with code {code}")); + let _ = std::fs::remove_file(&err_path); + ChildExit::Failure { code, message } + } + } else if libc::WIFSIGNALED(status) { + let sig = libc::WTERMSIG(status); + ChildExit::Failure { + code: -1, + message: format!("child killed by signal {sig}"), + } + } else { + ChildExit::Failure { + code: -1, + message: format!("child stopped with status {status}"), + } + } +} + +/// Non-unix stub — fork is Linux/macOS only. Beava ships on those platforms. +#[cfg(not(unix))] +pub async fn do_snapshot_via_fork( + _snapshot_dir: &Path, + _legacy_snapshot_lsn: u64, + _app_state: &AppState, +) -> Result { + Err(SnapshotForkError::ForkFailed(std::io::Error::new( + std::io::ErrorKind::Unsupported, + "fork-snapshot is unix-only", + ))) +} + +#[cfg(not(unix))] +pub async fn do_snapshot_via_fork_with_wait_timeout( + _snapshot_dir: &Path, + _legacy_snapshot_lsn: u64, + _app_state: &AppState, + _wait_timeout: std::time::Duration, +) -> Result { + Err(SnapshotForkError::ForkFailed(std::io::Error::new( + std::io::ErrorKind::Unsupported, + "fork-snapshot is unix-only", + ))) +} + +#[cfg(unix)] +fn snapshot_stats_sidecar_path(snapshot_dir: &Path, snapshot_lsn: u64) -> std::path::PathBuf { + snapshot_dir.join(format!("snapshot-{snapshot_lsn:016x}.stats")) +} + +#[cfg(unix)] +fn snapshot_error_sidecar_path(snapshot_dir: &Path, snapshot_lsn: u64) -> std::path::PathBuf { + snapshot_dir.join(format!("snapshot-{snapshot_lsn:016x}.error")) +} + +#[cfg(unix)] +fn snapshot_file_path(snapshot_dir: &Path, snapshot_lsn: u64) -> std::path::PathBuf { + snapshot_dir.join(format!( + "snapshot-{snapshot_lsn:016x}.{}", + beava_persistence::SNAPSHOT_EXT + )) +} + +#[cfg(unix)] +fn write_stats_sidecar( + snapshot_dir: &Path, + snapshot_lsn: u64, + stats: &SnapshotWriteStats, +) -> std::io::Result<()> { + let dir_fsync_us = stats + .dir_fsync_duration + .map(duration_micros) + .map(|us| us.to_string()) + .unwrap_or_else(|| "none".to_string()); + let body = format!( + "bytes={}\nfile_fsync_us={}\ndir_fsync_us={}\n", + stats.bytes, + duration_micros(stats.file_fsync_duration), + dir_fsync_us + ); + std::fs::write( + snapshot_stats_sidecar_path(snapshot_dir, snapshot_lsn), + body, + ) +} + +#[cfg(unix)] +fn read_stats_sidecar(snapshot_dir: &Path, snapshot_lsn: u64) -> Option { + let path = snapshot_stats_sidecar_path(snapshot_dir, snapshot_lsn); + let raw = match std::fs::read_to_string(&path) { + Ok(raw) => raw, + Err(_) => { + let _ = std::fs::remove_file(&path); + return None; + } + }; + let _ = std::fs::remove_file(&path); + + let bytes = parse_stats_field(&raw, "bytes")?.parse::().ok()?; + let file_fsync_us = parse_stats_field(&raw, "file_fsync_us")? + .parse::() + .ok()?; + let dir_fsync_duration = match parse_stats_field(&raw, "dir_fsync_us")? { + "none" => None, + value => Some(Duration::from_micros(value.parse::().ok()?)), + }; + + Some(SnapshotWriteStats { + path: snapshot_file_path(snapshot_dir, snapshot_lsn), + bytes, + file_fsync_duration: Duration::from_micros(file_fsync_us), + dir_fsync_duration, + }) +} + +#[cfg(unix)] +fn parse_stats_field<'a>(raw: &'a str, key: &str) -> Option<&'a str> { + let prefix = format!("{key}="); + raw.lines() + .find_map(|line| line.strip_prefix(&prefix).map(str::trim)) +} + +#[cfg(unix)] +fn duration_micros(duration: Duration) -> u64 { + duration.as_micros().min(u64::MAX as u128) as u64 +} + +/// Child-side fatal: write the error message to a sidecar file and `_exit(1)`. +/// Never returns. Marked `-> !` so callers don't need to handle a return. +#[cfg(unix)] +fn child_fail(snapshot_dir: &Path, snapshot_lsn: u64, msg: &str) -> ! { + let err_path = snapshot_error_sidecar_path(snapshot_dir, snapshot_lsn); + // Best-effort: ignore write failure. The parent will fall back to a + // generic "child exited non-zero" message. + let _ = std::fs::write(&err_path, msg); + unsafe { libc::_exit(1) } +} + +#[cfg(all(test, unix))] +mod tests { + use super::*; + use std::time::{SystemTime, UNIX_EPOCH}; + + fn temp_snapshot_dir(name: &str) -> PathBuf { + let nanos = SystemTime::now() + .duration_since(UNIX_EPOCH) + .unwrap() + .as_nanos(); + let dir = std::env::temp_dir().join(format!( + "beava-snapshot-fork-{name}-{}-{nanos}", + std::process::id() + )); + std::fs::create_dir_all(&dir).unwrap(); + dir + } + + #[test] + fn wait_for_snapshot_child_timeout_kills_and_reaps_child() { + let dir = temp_snapshot_dir("timeout-reap"); + let pid = unsafe { libc::fork() }; + assert!(pid >= 0, "fork failed: {}", std::io::Error::last_os_error()); + + if pid == 0 { + loop { + unsafe { + libc::pause(); + } + } + } + + let started = Instant::now(); + let exit = wait_for_snapshot_child(pid, dir.clone(), 42, Duration::from_millis(20)) + .expect("timeout path must return a bounded failure"); + let elapsed = started.elapsed(); + + match exit { + ChildExit::Failure { code, message } => { + assert_eq!(code, -1); + assert!( + message.contains("exceeded fork snapshot wait timeout"), + "{message}" + ); + assert!(message.contains("reaped signal"), "{message}"); + } + other => panic!("expected timeout failure, got {other:?}"), + } + assert!( + elapsed < Duration::from_secs(2), + "timeout/kill/reap path took {elapsed:?}" + ); + + let mut status: libc::c_int = 0; + let waited = unsafe { libc::waitpid(pid, &mut status, libc::WNOHANG) }; + assert_eq!(waited, -1, "child should already be reaped"); + assert_eq!( + std::io::Error::last_os_error().raw_os_error(), + Some(libc::ECHILD) + ); + + let _ = std::fs::remove_dir_all(dir); + } + + #[test] + fn stats_sidecar_roundtrip_reports_fsync_and_removes_file() { + let dir = temp_snapshot_dir("stats-sidecar"); + let snapshot_lsn = 77; + let stats = SnapshotWriteStats { + path: snapshot_file_path(&dir, snapshot_lsn), + bytes: 1234, + file_fsync_duration: Duration::from_micros(456), + dir_fsync_duration: Some(Duration::from_micros(789)), + }; + + write_stats_sidecar(&dir, snapshot_lsn, &stats).expect("write stats sidecar"); + let roundtrip = read_stats_sidecar(&dir, snapshot_lsn).expect("read stats sidecar"); + + assert_eq!(roundtrip.bytes, 1234); + assert_eq!(roundtrip.file_fsync_duration, Duration::from_micros(456)); + assert_eq!( + roundtrip.dir_fsync_duration, + Some(Duration::from_micros(789)) + ); + assert!( + !snapshot_stats_sidecar_path(&dir, snapshot_lsn).exists(), + "parent must remove stats sidecar after reading it" + ); + + let _ = std::fs::remove_dir_all(dir); + } +} diff --git a/crates/beava-server/src/snapshot_metrics.rs b/crates/beava-server/src/snapshot_metrics.rs new file mode 100644 index 00000000..ba7f644b --- /dev/null +++ b/crates/beava-server/src/snapshot_metrics.rs @@ -0,0 +1,31 @@ +use std::sync::atomic::{AtomicU64, Ordering}; +use std::time::Duration; + +static SNAPSHOT_LAST_DURATION_US: AtomicU64 = AtomicU64::new(0); +static SNAPSHOT_LAST_BYTES: AtomicU64 = AtomicU64::new(0); +static SNAPSHOT_LAST_FSYNC_US: AtomicU64 = AtomicU64::new(0); + +#[derive(Debug, Clone, Copy, Default)] +pub(crate) struct SnapshotMetricsSnapshot { + pub last_duration_us: u64, + pub last_bytes: u64, + pub last_fsync_us: u64, +} + +pub(crate) fn record_snapshot_success(duration: Duration, bytes: u64, fsync_duration: Duration) { + SNAPSHOT_LAST_DURATION_US.store(duration_micros(duration), Ordering::Relaxed); + SNAPSHOT_LAST_BYTES.store(bytes, Ordering::Relaxed); + SNAPSHOT_LAST_FSYNC_US.store(duration_micros(fsync_duration), Ordering::Relaxed); +} + +pub(crate) fn snapshot() -> SnapshotMetricsSnapshot { + SnapshotMetricsSnapshot { + last_duration_us: SNAPSHOT_LAST_DURATION_US.load(Ordering::Relaxed), + last_bytes: SNAPSHOT_LAST_BYTES.load(Ordering::Relaxed), + last_fsync_us: SNAPSHOT_LAST_FSYNC_US.load(Ordering::Relaxed), + } +} + +fn duration_micros(duration: Duration) -> u64 { + duration.as_micros().min(u64::MAX as u128) as u64 +} diff --git a/crates/beava-server/src/snapshot_task.rs b/crates/beava-server/src/snapshot_task.rs index e7d12e6b..9ade0cbb 100644 --- a/crates/beava-server/src/snapshot_task.rs +++ b/crates/beava-server/src/snapshot_task.rs @@ -1,16 +1,19 @@ -//! Periodic snapshot task: captures `wal_sink.durable_lsn()`, encodes the -//! live registry + state tables outside the lock, atomic-renames into the -//! snapshot dir, then truncates the WAL up to the snapshot LSN and prunes -//! old snapshots. A manual-trigger channel lets tests force an immediate -//! snapshot via `TestServer::force_snapshot_now`. +//! Periodic snapshot task: captures the highest applied WAL watermark, captures +//! live registry + state tables, encodes outside the apply lock, atomic-renames +//! into the snapshot dir, then prunes/reclaims WAL state covered by the +//! snapshot LSN and prunes old snapshots. A manual-trigger channel lets tests +//! force an immediate snapshot via `TestServer::force_snapshot_now`. use crate::AppState; use beava_core::snapshot_body::SnapshotBody; -use beava_persistence::{prune_old_snapshots, PersistError, SnapshotWriter, WalSink}; -use std::path::PathBuf; +use beava_persistence::{ + prune_old_snapshots, PersistError, SnapshotWriteStats, SnapshotWriter, WalSink, +}; +use beava_runtime_core::wal_writer::WalReclaimHandle; +use std::path::{Path, PathBuf}; use std::sync::atomic::Ordering; use std::sync::Arc; -use std::time::Duration; +use std::time::{Duration, Instant}; use tokio::sync::{mpsc, oneshot}; use tokio::task::JoinHandle; use tokio_util::sync::CancellationToken; @@ -21,6 +24,38 @@ pub struct SnapshotTaskConfig { pub interval: Duration, pub snapshot_dir: PathBuf, pub retain: usize, + /// Minimum number of WAL events written since the previous successful + /// snapshot that must have accumulated before the next interval tick + /// fires a snapshot. `0` (default) preserves the legacy "always snapshot + /// on every tick" behavior; any value > 0 enables Redis-style + /// conditional snapshotting — idle minutes don't write a snapshot. + /// + /// Computed as `current_wal_lsn - last_snapshot_lsn`. The check is + /// applied to interval ticks only; a manual `force_snapshot_now` + /// trigger always runs regardless of threshold. + /// + /// Wired from env `BEAVA_SNAPSHOT_MIN_EVENTS`. + pub min_events_per_snapshot: u64, + /// Whether to use the fork+COW snapshot path (drops apply-thread + /// lock-hold from seconds to microseconds). Resolved once at boot in + /// `server.rs` from `BEAVA_SNAPSHOT_FORK=1`; tests construct + /// `SnapshotTaskConfig` with this field set directly to avoid + /// process-env pollution (per the Phase 13.5.3 architectural rule + /// in `phase13_5_3_no_env_var_pokes_in_tests`). + pub use_fork_snapshot: bool, + /// Test-only synchronization hook: receives the LSN captured for an + /// in-process snapshot immediately before `state_tables.lock()`. + #[doc(hidden)] + pub snapshot_lsn_capture_tx: Option>, +} + +/// Read `BEAVA_SNAPSHOT_MIN_EVENTS` as a u64. Returns `0` if the env is +/// unset or unparseable (preserves legacy behavior). +pub fn min_events_from_env() -> u64 { + std::env::var("BEAVA_SNAPSHOT_MIN_EVENTS") + .ok() + .and_then(|v| v.parse::().ok()) + .unwrap_or(0) } /// Trigger channel sender for `force_snapshot_now`. @@ -40,15 +75,25 @@ pub fn spawn_snapshot_task( cfg: SnapshotTaskConfig, app_state: Arc, wal_sink: WalSink, + wal_reclaim: Option, cancel: CancellationToken, ) -> (JoinHandle<()>, SnapshotTriggerTx) { let (trigger_tx, mut trigger_rx) = mpsc::channel::>>(8); let join = tokio::spawn(async move { + // Read last_snapshot_lsn BEFORE consuming the first interval tick. + // The first tick is "immediate" (Tokio docs) but may still yield to + // the runtime to set up the timer — yielding here would let + // concurrent appends advance the LSN before we observe the + // baseline, causing the first real tick to see `delta = 0` and + // skip even though events DID accumulate. + let mut last_snapshot_lsn: u64 = current_snapshot_lsn(&app_state, &wal_sink); + let mut iv = tokio::time::interval(cfg.interval); iv.set_missed_tick_behavior(tokio::time::MissedTickBehavior::Skip); // First interval tick fires immediately; skip it so boot doesn't // race a snapshot before the WAL has any records. iv.tick().await; + loop { tokio::select! { biased; @@ -61,18 +106,54 @@ pub fn spawn_snapshot_task( return; } Some(ack) = trigger_rx.recv() => { - let res = do_snapshot(&cfg, &app_state, &wal_sink).await; - let mapped = res.map_err(|e| e.to_string()); + // Manual trigger always runs regardless of threshold. + // Tests + operators use this to force a snapshot. + let res = do_snapshot(&cfg, &app_state, &wal_sink, wal_reclaim.as_ref()).await; + let mapped = match res { + Ok(snapshot_lsn) => { + last_snapshot_lsn = snapshot_lsn; + Ok(()) + } + Err(e) => Err(e.to_string()), + }; let _ = ack.send(mapped); } _ = iv.tick() => { - if let Err(e) = do_snapshot(&cfg, &app_state, &wal_sink).await { - tracing::warn!( - target: "beava.snapshot", - kind = "snapshot.tick_failed", - error = %e, - "scheduled snapshot failed" - ); + // Redis-style conditional skip. When + // `min_events_per_snapshot > 0`, an interval tick is a + // no-op if fewer than `min` WAL events have committed + // since the previous successful snapshot. This avoids + // the production write-amplification class where an + // idle beava still writes a multi-hundred-MB snapshot + // every 30-60 s. Default `0` preserves legacy behavior. + if cfg.min_events_per_snapshot > 0 { + let current_lsn = current_snapshot_lsn(&app_state, &wal_sink); + let delta = current_lsn.saturating_sub(last_snapshot_lsn); + if delta < cfg.min_events_per_snapshot { + tracing::debug!( + target: "beava.snapshot", + kind = "snapshot.skipped_below_threshold", + events_since_last = delta, + threshold = cfg.min_events_per_snapshot, + current_lsn, + last_snapshot_lsn, + "skipping snapshot — below event-count threshold" + ); + continue; + } + } + match do_snapshot(&cfg, &app_state, &wal_sink, wal_reclaim.as_ref()).await { + Ok(snapshot_lsn) => { + last_snapshot_lsn = snapshot_lsn; + } + Err(e) => { + tracing::warn!( + target: "beava.snapshot", + kind = "snapshot.tick_failed", + error = %e, + "scheduled snapshot failed" + ); + } } } } @@ -85,22 +166,92 @@ async fn do_snapshot( cfg: &SnapshotTaskConfig, app_state: &AppState, wal_sink: &WalSink, -) -> Result<(), SnapshotTaskError> { + wal_reclaim: Option<&WalReclaimHandle>, +) -> Result { #[cfg(any(feature = "testing", test))] maybe_crash_at("before-snapshot"); - // Capture `durable_lsn` FIRST so `snapshot_lsn ≤ actual covered state`. - // Any WAL record past this LSN is safely re-applied on restart — Event - // records are idempotent through `apply_event_to_aggregations`, - // RegistryBump records are additive. - let snapshot_lsn = wal_sink.durable_lsn(); - let next_event_id = app_state.dev_agg.next_event_id.load(Ordering::Relaxed); - let query_time_ms = app_state.dev_agg.query_time_ms.load(Ordering::Relaxed) as i64; + let snapshot_started = Instant::now(); + let legacy_snapshot_lsn = wal_sink.durable_lsn(); - let body = { - let registry_snap = app_state.dev_agg.registry.snapshot(); + // Dispatch on `BEAVA_SNAPSHOT_FORK=1` — the fork+COW path drops apply- + // thread lock-hold from ~seconds to ~µs at the cost of a brief 2× memory + // peak during the child's serialize+write window. See `snapshot_fork` + // for the safety analysis. Default (env unset) is the legacy in-process + // path below. + if cfg.use_fork_snapshot { + match crate::snapshot_fork::do_snapshot_via_fork( + &cfg.snapshot_dir, + legacy_snapshot_lsn, + app_state, + ) + .await + { + Ok(crate::snapshot_fork::ChildExit::Success { + snapshot_lsn, + write_stats, + }) => { + let mut legacy_segments_removed = 0; + let mut handrolled_reclaim_requested = false; + if snapshot_lsn > 0 { + legacy_segments_removed = wal_sink.truncate_up_to(snapshot_lsn).await?; + if let Some(reclaim) = wal_reclaim { + reclaim.request_reclaim_up_to(snapshot_lsn); + handrolled_reclaim_requested = true; + } + } + let removed = prune_old_snapshots(&cfg.snapshot_dir, cfg.retain)?; + let registry_version = app_state.dev_agg.registry.version(); + let total_duration = snapshot_started.elapsed(); + let (snapshot_bytes, fsync_duration) = + snapshot_write_metrics(&cfg.snapshot_dir, snapshot_lsn, write_stats.as_ref()); + crate::snapshot_metrics::record_snapshot_success( + total_duration, + snapshot_bytes, + fsync_duration, + ); + tracing::info!( + target: "beava.snapshot", + kind = "snapshot.written", + snapshot_lsn, + registry_version, + duration_ms = total_duration.as_secs_f64() * 1000.0, + bytes = snapshot_bytes, + fsync_ms = fsync_duration.as_secs_f64() * 1000.0, + retained = cfg.retain, + snapshots_removed = removed, + legacy_wal_segments_removed = legacy_segments_removed, + handrolled_wal_reclaim_requested = handrolled_reclaim_requested, + via = "fork", + "snapshot written via fork; covered WAL reclamation queued" + ); + return Ok(snapshot_lsn); + } + Ok(crate::snapshot_fork::ChildExit::Failure { code, message }) => { + return Err(SnapshotTaskError::Encode(format!( + "fork-snapshot child failed (code={code}): {message}" + ))); + } + Err(e) => { + return Err(SnapshotTaskError::Encode(format!("fork-snapshot: {e}"))); + } + } + } + + // Legacy in-process path (default). + let (snapshot_lsn, body) = { + let captured_lsn = + legacy_snapshot_lsn.max(app_state.dev_agg.next_event_id.load(Ordering::Acquire)); + if let Some(tx) = &cfg.snapshot_lsn_capture_tx { + let _ = tx.send(captured_lsn); + } let tables = app_state.dev_agg.state_tables.lock(); - SnapshotBody::from_live(®istry_snap, &tables, next_event_id, query_time_ms) + let registry_snap = app_state.dev_agg.registry.snapshot(); + let next_event_id = app_state.dev_agg.next_event_id.load(Ordering::Acquire); + let query_time_ms = app_state.dev_agg.query_time_ms.load(Ordering::Acquire) as i64; + let snapshot_lsn = legacy_snapshot_lsn.max(next_event_id); + let body = SnapshotBody::from_live(®istry_snap, &tables, next_event_id, query_time_ms); + (snapshot_lsn, body) }; let registry_version = body.registry.version; let encoded = body @@ -110,26 +261,75 @@ async fn do_snapshot( #[cfg(any(feature = "testing", test))] maybe_crash_at("before-rename"); - SnapshotWriter::write(&cfg.snapshot_dir, snapshot_lsn, registry_version, &encoded)?; + let write_stats = SnapshotWriter::write_with_stats( + &cfg.snapshot_dir, + snapshot_lsn, + registry_version, + &encoded, + )?; #[cfg(any(feature = "testing", test))] maybe_crash_at("after-rename-before-truncate"); + let mut legacy_segments_removed = 0; + let mut handrolled_reclaim_requested = false; if snapshot_lsn > 0 { - wal_sink.truncate_up_to(snapshot_lsn).await?; + legacy_segments_removed = wal_sink.truncate_up_to(snapshot_lsn).await?; + if let Some(reclaim) = wal_reclaim { + reclaim.request_reclaim_up_to(snapshot_lsn); + handrolled_reclaim_requested = true; + } } let removed = prune_old_snapshots(&cfg.snapshot_dir, cfg.retain)?; + let total_duration = snapshot_started.elapsed(); + let fsync_duration = write_stats.total_fsync_duration(); + crate::snapshot_metrics::record_snapshot_success( + total_duration, + write_stats.bytes, + fsync_duration, + ); tracing::info!( target: "beava.snapshot", kind = "snapshot.written", snapshot_lsn, registry_version, + duration_ms = total_duration.as_secs_f64() * 1000.0, + bytes = write_stats.bytes, + fsync_ms = fsync_duration.as_secs_f64() * 1000.0, retained = cfg.retain, - removed, - "snapshot written + WAL truncated + old snapshots pruned" + snapshots_removed = removed, + legacy_wal_segments_removed = legacy_segments_removed, + handrolled_wal_reclaim_requested = handrolled_reclaim_requested, + "snapshot written; covered WAL reclamation queued" ); - Ok(()) + Ok(snapshot_lsn) +} + +fn current_snapshot_lsn(app_state: &AppState, wal_sink: &WalSink) -> u64 { + wal_sink + .durable_lsn() + .max(app_state.dev_agg.next_event_id.load(Ordering::Acquire)) +} + +fn snapshot_write_metrics( + snapshot_dir: &Path, + snapshot_lsn: u64, + write_stats: Option<&SnapshotWriteStats>, +) -> (u64, Duration) { + if let Some(stats) = write_stats { + return (stats.bytes, stats.total_fsync_duration()); + } + + let bytes = snapshot_dir + .join(format!( + "snapshot-{snapshot_lsn:016x}.{}", + beava_persistence::SNAPSHOT_EXT + )) + .metadata() + .map(|m| m.len()) + .unwrap_or(0); + (bytes, Duration::ZERO) } #[cfg(any(feature = "testing", test))] diff --git a/crates/beava-server/src/testing.rs b/crates/beava-server/src/testing.rs index 3f518f84..59ce5b2c 100644 --- a/crates/beava-server/src/testing.rs +++ b/crates/beava-server/src/testing.rs @@ -488,7 +488,8 @@ impl TestServer { } /// Force the periodic snapshot task to run NOW. Resolves once the - /// snapshot has been written, WAL truncated, and old snapshots pruned. + /// snapshot has been written, covered WAL reclamation has been queued, + /// and old snapshots have been pruned. /// Returns an error if the snapshot task has stopped or the snapshot /// itself failed. pub async fn force_snapshot_now(&self) -> Result<(), String> { diff --git a/crates/beava-server/src/thp.rs b/crates/beava-server/src/thp.rs new file mode 100644 index 00000000..60191a8e --- /dev/null +++ b/crates/beava-server/src/thp.rs @@ -0,0 +1,116 @@ +//! Transparent Huge Pages (THP) detection + self-opt-out. +//! +//! Why this exists: +//! - THP is a Linux feature that promotes 4 KB pages to 2 MB pages. +//! - With THP enabled, fork()'s copy-on-write (COW) granularity is 2 MB +//! instead of 4 KB — modifying ONE byte during a snapshot copies a +//! full 2 MB page. That's a 500× amplifier on COW memory overhead. +//! - Redis's well-known startup warning ("WARNING you have Transparent +//! Huge Pages (THP) support enabled in your kernel") exists for the +//! same reason — BGSAVE pays the same cost. +//! +//! What this module does (Linux only): +//! 1. Reads `/sys/kernel/mm/transparent_hugepage/enabled` and logs a +//! structured WARN if the kernel default is `[always]`. +//! 2. Calls `prctl(PR_SET_THP_DISABLE, 1)` to opt THIS PROCESS out of +//! THP regardless of the system-wide setting. This is the +//! self-protection Redis-clone projects also do (KeyDB, +//! Dragonfly, etc.). +//! +//! Non-Linux platforms (macOS, *BSD) have no THP — this module is a +//! no-op there. + +#[cfg(target_os = "linux")] +const THP_ENABLED_PATH: &str = "/sys/kernel/mm/transparent_hugepage/enabled"; + +/// Detect kernel THP setting + opt this process out. Safe to call +/// multiple times; idempotent. +pub fn detect_and_opt_out() { + #[cfg(target_os = "linux")] + { + // 1. Detect system-wide setting for operator awareness. + match std::fs::read_to_string(THP_ENABLED_PATH) { + Ok(s) => { + let trimmed = s.trim(); + if trimmed.contains("[always]") { + tracing::warn!( + target: "beava.thp", + kind = "thp.system_always_enabled", + setting = %trimmed, + path = THP_ENABLED_PATH, + "Transparent Huge Pages (THP) is set to `always` system-wide. \ + beava is opting this process out via prctl, but operators should \ + set THP to `madvise` or `never` system-wide for best fork+COW \ + performance: \ + `echo madvise > /sys/kernel/mm/transparent_hugepage/enabled` \ + (or kernel boot param `transparent_hugepage=madvise`). \ + See: https://redis.io/docs/latest/operate/oss_and_stack/management/optimization/latency/#latency-induced-by-transparent-huge-pages" + ); + } else { + tracing::debug!( + target: "beava.thp", + kind = "thp.system_setting", + setting = %trimmed, + "system THP setting (recommended: `madvise` or `never`)" + ); + } + } + Err(e) => { + // /sys/kernel/mm may not exist on all kernels / containers; + // not a problem — just log at debug. + tracing::debug!( + target: "beava.thp", + kind = "thp.sys_unreadable", + error = %e, + "could not read THP setting (non-Linux kernel or sandboxed /sys)" + ); + } + } + + // 2. Self-opt-out for this process. PR_SET_THP_DISABLE = 41. + // SAFETY: prctl is async-signal-safe and has no parameter aliasing + // concerns; the only effect of failure is the process stays + // subject to system THP (we log the failure and move on). + let ret = unsafe { libc::prctl(libc::PR_SET_THP_DISABLE, 1u64, 0u64, 0u64, 0u64) }; + if ret == 0 { + tracing::debug!( + target: "beava.thp", + kind = "thp.process_opt_out_ok", + "process opted out of THP via prctl(PR_SET_THP_DISABLE) — \ + fork()+COW page granularity now 4 KB regardless of system setting" + ); + } else { + let err = std::io::Error::last_os_error(); + tracing::warn!( + target: "beava.thp", + kind = "thp.process_opt_out_failed", + error = %err, + "prctl(PR_SET_THP_DISABLE) failed; this process may still pay \ + 2 MB-page COW cost during snapshots if system THP is enabled" + ); + } + } + + // macOS / *BSD: no THP, no work to do. + #[cfg(not(target_os = "linux"))] + { + tracing::debug!( + target: "beava.thp", + kind = "thp.not_applicable", + "THP check skipped (non-Linux platform)" + ); + } +} + +#[cfg(test)] +mod tests { + use super::*; + + #[test] + fn detect_and_opt_out_does_not_panic() { + // Idempotent + side-effect-only — just verify the call doesn't + // explode on either Linux or macOS. + detect_and_opt_out(); + detect_and_opt_out(); + } +} diff --git a/crates/beava-server/tests/phase13_4_force_register.rs b/crates/beava-server/tests/phase13_4_force_register.rs index 0f6ff8fd..76c597e6 100644 --- a/crates/beava-server/tests/phase13_4_force_register.rs +++ b/crates/beava-server/tests/phase13_4_force_register.rs @@ -399,8 +399,8 @@ async fn register_destructive_agg_removal_without_force_returns_409() { // 409'd — even with `force=true` set on the request body. // // Fixed behavior: with `force=true`, additive entries that target an -// existing descriptor (NewField on event, NewAgg on table) MUST also be -// pre-removed so execute_register sees them as fully new. The +// existing descriptor (NewField on event, NewAgg on table) MUST also land +// through the durable force-removal path before re-install. The // caller-explicit `force=true` carries the "drop existing state" intent // for both destructive AND additive-against-existing changes. #[tokio::test(flavor = "multi_thread", worker_threads = 4)] diff --git a/crates/beava-server/tests/phase18_09_msgpack_tcp_test.rs b/crates/beava-server/tests/phase18_09_msgpack_tcp_test.rs index c6312595..2d53775c 100644 --- a/crates/beava-server/tests/phase18_09_msgpack_tcp_test.rs +++ b/crates/beava-server/tests/phase18_09_msgpack_tcp_test.rs @@ -3,8 +3,8 @@ //! Tasks covered: //! 9.2 — parse_wire_request handles CT_MSGPACK envelope //! 9.4 — dispatch_push_sync handles msgpack body format end-to-end -//! 9.5 — WAL record v=2 binary header written for msgpack push -//! 9.6 — WAL replay handles v=2 (msgpack) + mixed v=1/v=2 records +//! 9.5 — WAL record v=3 binary header written for msgpack push +//! 9.6 — WAL replay handles msgpack records after restart // ─── Task 9.2 RED: parse_wire_request handles msgpack envelope ──────────────── // @@ -339,13 +339,13 @@ async fn test_dispatch_push_json_body_still_works() { let _ = tokio::time::timeout(std::time::Duration::from_secs(5), serve_task).await; } -// ─── Task 9.5 RED: WAL record v=2 binary header ─────────────────────────────── +// ─── Task 9.5: WAL record v=3 binary header ─────────────────────────────────── // // Pushes via TCP/msgpack, reads the WAL file directly, asserts first record -// starts with [0x02, 0x02, ...] (v=2, body_format=msgpack). +// starts with [0x03, assigned_lsn, 0x02, ...] (v=3, body_format=msgpack). #[tokio::test(flavor = "multi_thread", worker_threads = 2)] -async fn test_wal_record_v2_format() { +async fn test_wal_record_v3_format() { { let _g = SERVER_SERIALIZER_09.lock().unwrap(); } // serialise test start; _g drops before any await @@ -386,7 +386,7 @@ async fn test_wal_record_v2_format() { .await .expect("register"); - // Send a msgpack push so a v=2 WAL record is written. + // Send a msgpack push so a v=3 WAL record is written. let body = serde_json::json!({"user_id": "waltest", "amount": 7.0, "event_time": 2_000_000_i64}); let _ = send_msgpack_push_tcp(tcp_addr, "TxnEvent", &body).await; @@ -400,7 +400,7 @@ async fn test_wal_record_v2_format() { // Read the WAL directory and find the data-plane WAL file. // The hand-rolled WalWriter creates "wal-0000000000000000.wal". - // The first record should start with v=2, body_format=CT_MSGPACK. + // The first record should start with v=3, assigned_lsn, body_format=CT_MSGPACK. let wal_files: Vec<_> = std::fs::read_dir(&wal_path) .expect("read wal dir") .filter_map(|e| e.ok()) @@ -410,12 +410,11 @@ async fn test_wal_record_v2_format() { }) .collect(); - // WAL files present = v=2 records were written (the WalWriter creates them). - // If no WAL files exist, the WalBufferRing hasn't flushed — this indicates - // the v=2 WAL append path is not yet implemented. Fail explicitly. + // WAL files present = v3 records were written (the WalWriter creates them). + // If no WAL files exist, the WalBufferRing hasn't flushed. Fail explicitly. assert!( !wal_files.is_empty(), - "expected at least one WAL .wal file after msgpack push; v=2 WAL append not yet wired" + "expected at least one WAL .wal file after msgpack push; v3 WAL append not yet wired" ); // Read the first WAL file and check the record format. @@ -423,29 +422,33 @@ async fn test_wal_record_v2_format() { let wal_bytes = std::fs::read(wal_file_path).expect("read wal file"); assert!(!wal_bytes.is_empty(), "WAL file should not be empty"); - // v=2 record format: [u8 v=2][u8 body_format][u32 rv][u64 et_ms][u16 event_name_len][...name...][u32 body_len][...body...] - // First byte must be 0x02 (record version 2). + // v3 record format: [u8 v=3][u64 assigned_lsn][u8 body_format][u32 rv][u64 et_ms][u16 event_name_len][...name...][u32 body_len][...body...] + // First byte must be 0x03 (record version 3). assert_eq!( - wal_bytes[0], 0x02, - "first WAL record byte must be version=2 (0x02), got {:#04x}", + wal_bytes[0], 0x03, + "first WAL record byte must be version=3 (0x03), got {:#04x}", wal_bytes[0] ); - // Second byte must be 0x02 (CT_MSGPACK body format). + assert!( + wal_bytes.len() >= 10, + "v3 WAL record should include version + assigned_lsn + body_format" + ); + let assigned_lsn = u64::from_be_bytes(wal_bytes[1..9].try_into().unwrap()); + assert!(assigned_lsn > 0, "assigned_lsn must be non-zero"); + // Byte 9 must be 0x02 (CT_MSGPACK body format). assert_eq!( - wal_bytes[1], CT_MSGPACK, - "second WAL record byte must be CT_MSGPACK (0x02), got {:#04x}", - wal_bytes[1] + wal_bytes[9], CT_MSGPACK, + "v3 WAL body_format byte must be CT_MSGPACK (0x02), got {:#04x}", + wal_bytes[9] ); } -// ─── Task 9.6 RED: WAL replay handles v=2 + mixed v=1/v=2 ─────────────────── +// ─── Task 9.6: WAL replay handles msgpack records after restart ────────────── #[tokio::test(flavor = "multi_thread", worker_threads = 2)] async fn test_wal_replay_v2_msgpack() { // This test verifies that after a server restart, state built from a - // msgpack (v=2) push is correctly replayed from the WAL. - // RED: the v=2 WAL format is not yet implemented, so this test will fail - // until Task 9.5 GREEN + 9.6 GREEN land. + // msgpack push is correctly replayed from the WAL. { let _g = SERVER_SERIALIZER_09.lock().unwrap(); } // serialise test start; _g drops before any await @@ -539,10 +542,8 @@ async fn test_wal_replay_v2_msgpack() { "count should be 3 after WAL replay of 3 msgpack events" ); } else { - // If the endpoint returns 404/error, WAL replay hasn't reconstituted - // the aggregation state from v=2 records — this is the RED condition. panic!( - "GET /get/cnt/replay_user failed with status {}; v=2 WAL replay not yet implemented", + "GET /get/cnt/replay_user failed with status {}; WAL replay did not restore msgpack state", get_resp.status() ); } diff --git a/crates/beava-server/tests/phase6_push.rs b/crates/beava-server/tests/phase6_push.rs index 4c32696d..f57eb1d6 100644 --- a/crates/beava-server/tests/phase6_push.rs +++ b/crates/beava-server/tests/phase6_push.rs @@ -35,9 +35,10 @@ async fn register_transaction( "fields": { "event_time": "i64", "user_id": "str", - "amount": "f64" + "amount": "f64", + "metadata": "json" }, - "optional_fields": [] + "optional_fields": ["metadata"] }, }); if let Some(k) = dedupe_key { @@ -80,12 +81,20 @@ async fn push_raw( ts: &beava_server::testing::TestServer, event_name: &str, body: &serde_json::Value, +) -> reqwest::Response { + push_raw_bytes(ts, event_name, serde_json::to_vec(body).unwrap()).await +} + +async fn push_raw_bytes( + ts: &beava_server::testing::TestServer, + event_name: &str, + body: Vec, ) -> reqwest::Response { let url = format!("{}/push/{}", ts.base_url(), event_name); reqwest::Client::new() .post(&url) .header("Content-Type", "application/json") - .body(serde_json::to_vec(body).unwrap()) + .body(body) .timeout(Duration::from_secs(5)) .send() .await @@ -119,6 +128,108 @@ async fn push_happy_path_returns_ack_and_applies_event() { ts.shutdown().await.expect("shutdown"); } +#[tokio::test] +async fn push_rejects_control_characters_in_decoded_strings() { + let tmp = tempfile::tempdir().unwrap(); + let ts = spawn_with_wal(&tmp).await; + register_transaction(&ts, None, None).await; + + let resp = push_raw( + &ts, + "Transaction", + &json!({"user_id": "alice\u{0001}", "amount": 5.0, "event_time": 1_000_000}), + ) + .await; + assert_eq!(resp.status().as_u16(), 400); + let body: serde_json::Value = resp.json().await.expect("error body"); + assert_eq!(body["error"]["code"], "control_character_in_string"); + + ts.shutdown().await.expect("shutdown"); +} + +#[tokio::test] +async fn push_rejects_control_characters_in_field_names() { + let tmp = tempfile::tempdir().unwrap(); + let ts = spawn_with_wal(&tmp).await; + register_transaction(&ts, None, None).await; + + let resp = push_raw( + &ts, + "Transaction", + &json!({"user\u{0001}_id": "alice", "amount": 5.0, "event_time": 1_000_000}), + ) + .await; + assert_eq!(resp.status().as_u16(), 400); + let body: serde_json::Value = resp.json().await.expect("error body"); + assert_eq!(body["error"]["code"], "control_character_in_string"); + + ts.shutdown().await.expect("shutdown"); +} + +#[tokio::test] +async fn push_rejects_control_characters_in_nested_strings() { + let tmp = tempfile::tempdir().unwrap(); + let ts = spawn_with_wal(&tmp).await; + register_transaction(&ts, None, None).await; + + let resp = push_raw( + &ts, + "Transaction", + &json!({ + "user_id": "alice", + "amount": 5.0, + "event_time": 1_000_000, + "metadata": {"nested": ["ok", "bad\u{0007}"]} + }), + ) + .await; + assert_eq!(resp.status().as_u16(), 400); + let body: serde_json::Value = resp.json().await.expect("error body"); + assert_eq!(body["error"]["code"], "control_character_in_string"); + + ts.shutdown().await.expect("shutdown"); +} + +#[tokio::test] +async fn push_verb_rejects_control_characters_in_event_name() { + let tmp = tempfile::tempdir().unwrap(); + let ts = spawn_with_wal(&tmp).await; + register_transaction(&ts, None, None).await; + + let resp = ts + .post_json( + "/push", + &json!({ + "event": "Transaction\u{0001}", + "data": {"user_id": "alice", "amount": 5.0, "event_time": 1_000_000} + }), + ) + .await + .expect("post /push verb"); + assert_eq!(resp.status().as_u16(), 400); + let body: serde_json::Value = resp.json().await.expect("error body"); + assert_eq!(body["error"]["code"], "control_character_in_string"); + + ts.shutdown().await.expect("shutdown"); +} + +#[tokio::test] +async fn push_allows_json_whitespace_and_escaped_non_control_strings() { + let tmp = tempfile::tempdir().unwrap(); + let ts = spawn_with_wal(&tmp).await; + register_transaction(&ts, None, None).await; + + let body = br#"{ + "user_id": "alice \\n quote \" ok", + "amount": 5.0, + "event_time": 1000000 + }"#; + let resp = push_raw_bytes(&ts, "Transaction", body.to_vec()).await; + assert_eq!(resp.status().as_u16(), 200); + + ts.shutdown().await.expect("shutdown"); +} + #[tokio::test] async fn push_without_dedupe_key_bypasses_cache() { let tmp = tempfile::tempdir().unwrap(); diff --git a/crates/beava-server/tests/phase7_restart_cycle.rs b/crates/beava-server/tests/phase7_restart_cycle.rs index 8d0a0260..a199878c 100644 --- a/crates/beava-server/tests/phase7_restart_cycle.rs +++ b/crates/beava-server/tests/phase7_restart_cycle.rs @@ -19,6 +19,8 @@ use beava_server::testing::TestServerBuilder; use serde_json::json; +use std::path::Path; +use std::time::{Duration, Instant}; use tokio::sync::Mutex as TokioMutex; /// Plan 12.6-15: serialize ServerV18 boots so two restart-cycle tests don't @@ -127,6 +129,34 @@ async fn get_feature( serde_json::from_str(&body).expect("body json") } +fn handrolled_wal_len(wal_dir: &Path) -> u64 { + std::fs::read_dir(wal_dir) + .unwrap() + .filter_map(|e| e.ok()) + .map(|e| e.path()) + .filter(|p| p.extension().and_then(|s| s.to_str()) == Some("wal")) + .filter_map(|p| p.metadata().ok().map(|m| m.len())) + .sum() +} + +async fn wait_for_wal_len(wal_dir: &Path, pred: F) -> u64 +where + F: Fn(u64) -> bool, +{ + let deadline = Instant::now() + Duration::from_secs(5); + loop { + let len = handrolled_wal_len(wal_dir); + if pred(len) { + return len; + } + assert!( + Instant::now() < deadline, + "timed out waiting for hand-rolled WAL length condition; current len={len}" + ); + tokio::time::sleep(Duration::from_millis(10)).await; + } +} + /// SC1: snapshot atomic write → reproducible state after restart from /// snapshot + WAL-past-LSN. /// @@ -298,6 +328,236 @@ async fn sc4_schema_evolution_survives_restart() { } } +/// Registry WAL records can advance the durable legacy LSN before the first +/// data-plane push. The ring WAL must jump past that LSN so a later snapshot +/// can use one LSN to cover both `.log` registry records and `.wal` events +/// without skipping post-snapshot push records on restart. +#[tokio::test] +async fn registry_first_snapshot_replays_post_snapshot_push_tail() { + let _serializer_guard = RESTART_CYCLE_SERIALIZER.lock().await; + let wal = tempfile::tempdir().unwrap(); + let snap = tempfile::tempdir().unwrap(); + + { + let ts = TestServerBuilder::new() + .dev_endpoints(true) + .wal_dir(wal.path().to_path_buf()) + .snapshot_dir(snap.path().to_path_buf()) + .fsync_interval_ms(1) + .spawn() + .await + .expect("spawn 1st"); + + register(&ts, json!([txn_descriptor(), txn_agg_descriptor()])).await; + for i in 0..5_i64 { + push_event( + &ts, + "Txn", + json!({"user_id": "alice", "amount": 1.0, "event_time": 1_000_000 + i}), + ) + .await; + } + + ts.force_snapshot_now().await.expect("force snapshot"); + let snapshots = beava_persistence::list_snapshots(snap.path()).expect("list snapshots"); + let (_, snapshot_path) = snapshots.first().expect("snapshot exists after force"); + let (_, snapshot_bytes) = + beava_persistence::SnapshotReader::open(snapshot_path).expect("open snapshot"); + let snapshot_body = + beava_core::snapshot_body::SnapshotBody::decode(&snapshot_bytes).expect("decode"); + assert_eq!(snapshot_body.registry.version, 1); + assert!(snapshot_body.next_event_id > 1); + assert_eq!( + snapshot_body + .state_tables + .get("TxnAgg") + .map(|entries| entries.len()), + Some(1), + "forced snapshot should include the pre-tail TxnAgg state" + ); + + for i in 0..4_i64 { + push_event( + &ts, + "Txn", + json!({"user_id": "alice", "amount": 1.0, "event_time": 2_000_000 + i}), + ) + .await; + } + + let v = get_feature(&ts, "TxnAgg", "alice", &["cnt"]).await; + assert_eq!(v["cnt"], 9, "pre-restart cnt expected 9, got {v}"); + + ts.shutdown().await.expect("shutdown 1st"); + } + + { + let ts = TestServerBuilder::new() + .dev_endpoints(true) + .wal_dir(wal.path().to_path_buf()) + .snapshot_dir(snap.path().to_path_buf()) + .fsync_interval_ms(1) + .spawn() + .await + .expect("spawn 2nd"); + + let v = get_feature(&ts, "TxnAgg", "alice", &["cnt"]).await; + assert_eq!( + v["cnt"], 9, + "post-restart cnt expected 9 (snapshot + post-snapshot WAL tail), got {v}" + ); + + ts.shutdown().await.expect("shutdown 2nd"); + } +} + +#[tokio::test] +async fn compacted_handrolled_wal_restarts_with_retained_tail() { + let _serializer_guard = RESTART_CYCLE_SERIALIZER.lock().await; + let wal = tempfile::tempdir().unwrap(); + let snap = tempfile::tempdir().unwrap(); + + { + let ts = TestServerBuilder::new() + .dev_endpoints(true) + .wal_dir(wal.path().to_path_buf()) + .snapshot_dir(snap.path().to_path_buf()) + .fsync_interval_ms(1) + .wal_tick_ms(1) + .spawn() + .await + .expect("spawn 1st"); + + register(&ts, json!([txn_descriptor(), txn_agg_descriptor()])).await; + for i in 0..12_i64 { + push_event( + &ts, + "Txn", + json!({"user_id": "alice", "amount": 1.0, "event_time": 1_000_000 + i}), + ) + .await; + } + + let before_len = wait_for_wal_len(wal.path(), |len| len > 0).await; + ts.force_snapshot_now().await.expect("force snapshot"); + let compacted_len = wait_for_wal_len(wal.path(), |len| len < before_len).await; + + for i in 0..3_i64 { + push_event( + &ts, + "Txn", + json!({"user_id": "alice", "amount": 1.0, "event_time": 2_000_000 + i}), + ) + .await; + } + let _tail_len = wait_for_wal_len(wal.path(), |len| len > compacted_len).await; + + let v = get_feature(&ts, "TxnAgg", "alice", &["cnt"]).await; + assert_eq!(v["cnt"], 15, "pre-restart cnt expected 15, got {v}"); + + ts.shutdown().await.expect("shutdown 1st"); + } + + { + let ts = TestServerBuilder::new() + .dev_endpoints(true) + .wal_dir(wal.path().to_path_buf()) + .snapshot_dir(snap.path().to_path_buf()) + .fsync_interval_ms(1) + .wal_tick_ms(1) + .spawn() + .await + .expect("spawn 2nd"); + + let v = get_feature(&ts, "TxnAgg", "alice", &["cnt"]).await; + assert_eq!( + v["cnt"], 15, + "post-restart cnt expected 15: snapshot-covered prefix plus retained compacted WAL tail, got {v}" + ); + + ts.shutdown().await.expect("shutdown 2nd"); + } +} + +/// Regression for the recovery replay floor: a post-snapshot data-plane WAL +/// record can have an LSN lower than a later registry `.log` bump. Recovery +/// must still replay hand-rolled `.wal` records from `snapshot_lsn`, not from +/// the higher registry persistence LSN. +#[tokio::test] +async fn snapshot_then_push_then_schema_bump_replays_pre_bump_tail() { + let _serializer_guard = RESTART_CYCLE_SERIALIZER.lock().await; + let wal = tempfile::tempdir().unwrap(); + let snap = tempfile::tempdir().unwrap(); + + { + let ts = TestServerBuilder::new() + .dev_endpoints(true) + .wal_dir(wal.path().to_path_buf()) + .snapshot_dir(snap.path().to_path_buf()) + .fsync_interval_ms(1) + .spawn() + .await + .expect("spawn 1st"); + + register(&ts, json!([txn_descriptor(), txn_agg_descriptor()])).await; + for i in 0..5_i64 { + push_event( + &ts, + "Txn", + json!({"user_id": "alice", "amount": 1.0, "event_time": 1_000_000 + i}), + ) + .await; + } + + ts.force_snapshot_now().await.expect("force snapshot"); + + push_event( + &ts, + "Txn", + json!({"user_id": "alice", "amount": 1.0, "event_time": 2_000_000}), + ) + .await; + + register( + &ts, + json!([ + txn_descriptor(), + txn_agg_descriptor(), + click_descriptor(), + click_agg_descriptor() + ]), + ) + .await; + + let v = get_feature(&ts, "TxnAgg", "alice", &["cnt"]).await; + assert_eq!( + v["cnt"], 6, + "pre-restart cnt expected 6 after the post-snapshot pre-bump push, got {v}" + ); + + ts.shutdown().await.expect("shutdown 1st"); + } + + { + let ts = TestServerBuilder::new() + .dev_endpoints(true) + .wal_dir(wal.path().to_path_buf()) + .snapshot_dir(snap.path().to_path_buf()) + .fsync_interval_ms(1) + .spawn() + .await + .expect("spawn 2nd"); + + let v = get_feature(&ts, "TxnAgg", "alice", &["cnt"]).await; + assert_eq!( + v["cnt"], 6, + "post-restart cnt expected 6; replay must not skip the post-snapshot pre-bump WAL record even though the later RegistryBump has a higher LSN, got {v}" + ); + + ts.shutdown().await.expect("shutdown 2nd"); + } +} + /// Bonus: verify SC1 + SC4 combined — snapshot MID-WAY through schema /// evolution. Specifically: register A → push A → snapshot → register B → /// push A and B → shutdown → restart. Snapshot covers v1 schema; WAL tail diff --git a/crates/beava-server/tests/phase7_smoke.rs b/crates/beava-server/tests/phase7_smoke.rs index 3adb1831..dd21925f 100644 --- a/crates/beava-server/tests/phase7_smoke.rs +++ b/crates/beava-server/tests/phase7_smoke.rs @@ -17,6 +17,8 @@ use beava_server::testing::TestServerBuilder; use serde_json::json; +use std::path::Path; +use std::time::{Duration, Instant}; async fn register_txn_agg(ts: &beava_server::testing::TestServer) { let payload = json!({"nodes": [ @@ -63,7 +65,35 @@ async fn push_n_for_alice(ts: &beava_server::testing::TestServer, n: u64) { } } -/// SC3: WAL truncation after snapshot — confirm at least one WAL segment is +fn handrolled_wal_len(wal_dir: &Path) -> u64 { + std::fs::read_dir(wal_dir) + .unwrap() + .filter_map(|e| e.ok()) + .map(|e| e.path()) + .filter(|p| p.extension().and_then(|s| s.to_str()) == Some("wal")) + .filter_map(|p| p.metadata().ok().map(|m| m.len())) + .sum() +} + +async fn wait_for_wal_len(wal_dir: &Path, pred: F) -> u64 +where + F: Fn(u64) -> bool, +{ + let deadline = Instant::now() + Duration::from_secs(5); + loop { + let len = handrolled_wal_len(wal_dir); + if pred(len) { + return len; + } + assert!( + Instant::now() < deadline, + "timed out waiting for hand-rolled WAL length condition; current len={len}" + ); + tokio::time::sleep(Duration::from_millis(10)).await; + } +} + +/// SC3: WAL reclamation after snapshot — confirm at least one WAL segment is /// pruned when force_snapshot_now runs after segments accumulate. #[tokio::test] async fn sc3_truncate_releases_wal_past_snapshot() { @@ -106,6 +136,33 @@ async fn sc3_truncate_releases_wal_past_snapshot() { ts.shutdown().await.expect("shutdown"); } +#[tokio::test] +async fn snapshot_reclaims_handrolled_wal_file_bytes() { + let wal = tempfile::tempdir().unwrap(); + let snap = tempfile::tempdir().unwrap(); + let ts = TestServerBuilder::new() + .dev_endpoints(true) + .wal_dir(wal.path().to_path_buf()) + .snapshot_dir(snap.path().to_path_buf()) + .fsync_interval_ms(1) + .wal_tick_ms(1) + .spawn() + .await + .expect("spawn"); + register_txn_agg(&ts).await; + push_n_for_alice(&ts, 200).await; + + let before_len = wait_for_wal_len(wal.path(), |len| len > 0).await; + ts.force_snapshot_now().await.expect("force snapshot"); + let after_len = wait_for_wal_len(wal.path(), |len| len < before_len).await; + + assert!( + after_len < before_len, + "snapshot should reclaim hand-rolled .wal bytes (before={before_len}, after={after_len})" + ); + ts.shutdown().await.expect("shutdown"); +} + /// Recovery + snapshot machinery basic verification (single TestServer, no /// restart). Documents that registration → push → query works post-Phase 7 /// wiring without regressions vs Phase 6. diff --git a/crates/beava-server/tests/phase8_tcp_push.rs b/crates/beava-server/tests/phase8_tcp_push.rs index a8aaac28..f5356d3a 100644 --- a/crates/beava-server/tests/phase8_tcp_push.rs +++ b/crates/beava-server/tests/phase8_tcp_push.rs @@ -6,7 +6,7 @@ #![cfg(feature = "testing")] -use beava_core::wire::{OP_ERROR_RESPONSE, OP_PUSH}; +use beava_core::wire::{CT_JSON, OP_ERROR_RESPONSE, OP_PUSH}; use beava_server::testing::TestServerBuilder; use serde_json::json; use std::time::Duration; @@ -94,6 +94,25 @@ async fn tcp_push_unknown_event_returns_error() { ts.shutdown().await.expect("shutdown"); } +#[tokio::test] +async fn tcp_push_rejects_escaped_control_character_in_event_name() { + let ts = boot_with_transaction().await; + let mut tcp = ts.tcp_client().await.expect("tcp connect"); + + let payload = br#"{"event":"Transaction\u0001","body":{"event_time":1000,"user_id":"alice","amount":1.0}}"#; + let frame = tcp + .send_raw(OP_PUSH, CT_JSON, bytes::Bytes::copy_from_slice(payload)) + .await + .expect("raw tcp push"); + let body: serde_json::Value = serde_json::from_slice(&frame.payload).expect("json error body"); + + assert_eq!(frame.op, OP_ERROR_RESPONSE, "expected error frame"); + assert_eq!(body["error"]["code"], "control_character_in_string"); + + drop(tcp); + ts.shutdown().await.expect("shutdown"); +} + #[tokio::test] async fn tcp_push_invalid_body_returns_error() { let ts = boot_with_transaction().await; diff --git a/crates/beava-server/tests/snapshot_big_state.rs b/crates/beava-server/tests/snapshot_big_state.rs new file mode 100644 index 00000000..c25c8330 --- /dev/null +++ b/crates/beava-server/tests/snapshot_big_state.rs @@ -0,0 +1,364 @@ +//! Big-state snapshot tests — 500k → 5M entries, matching the production +//! incident scale (#151 reported a 507 MB encoded snapshot, ~5-10M entries). +//! +//! All tests are `#[ignore]`'d by default — building 5M entries × `AggOp` +//! takes ~10s and ~1 GB RAM, too heavy for default `cargo test`. +//! +//! ## How to run +//! +//! ```sh +//! # Recommended (release mode is ~10× faster — debug-mode AggOp::clone is +//! # bottlenecked by debug-assertions and panic stubs, masking real perf): +//! cargo test --release -p beava-server --test snapshot_big_state -- --ignored --nocapture +//! +//! # Single test: +//! cargo test --release -p beava-server --test snapshot_big_state \ +//! lock_hold_at_1m_entries -- --ignored --nocapture +//! ``` +//! +//! ## Why ignored by default +//! +//! - **Runtime:** ~30-60s end-to-end in release; ~5-10 min in debug. +//! - **Memory:** ~1 GB peak at 5M entries (entity-key strings + AggOp boxes). +//! +//! Default `cargo test` covers the same code paths at 100-200k entries +//! (`snapshot_lock_contention.rs`, `snapshot_recovery_time.rs`) — those +//! prove the contract; these tests confirm the contract still holds at +//! the production scale that triggered the incident. + +use beava_core::agg_op::AggOp; +use beava_core::agg_state::CountState; +use beava_core::agg_state_table::{AggStateTable, EntityKey}; +use beava_core::registry::Registry; +use beava_core::row::Value; +use beava_core::snapshot_body::{ + RegistryDescriptorsOnly, SerializedStateTables, SnapshotBody, SNAPSHOT_BODY_FORMAT_VERSION, +}; +use beava_persistence::{SnapshotReader, SnapshotWriter}; +use beava_server::registry_debug::DevAggState; +use beava_server::snapshot_fork::do_snapshot_via_fork; +use beava_server::AppState; +use compact_str::CompactString; +use smallvec::smallvec; +use std::collections::BTreeMap; +use std::sync::Arc; +use std::time::{Duration, Instant}; +use tempfile::TempDir; + +fn build_app_state(n_entities: usize) -> AppState { + let registry = Arc::new(Registry::new()); + let dev_agg = DevAggState::new(registry); + { + let mut tables = dev_agg.state_tables.lock(); + let mut table = AggStateTable::new(); + for ent in 0..n_entities { + let key_str = format!("user_{ent:09}"); + let entity_key = EntityKey(smallvec![( + CompactString::from("user_id"), + Value::Str(CompactString::from(key_str.as_str())), + )]); + table.insert_from_entity_key( + entity_key, + vec![AggOp::Count(CountState { n: ent as u64 })], + ); + } + tables.push(table); + } + let (wal_sink, _wal_join) = beava_persistence::WalSink::spawn_no_op(); + let idem_cache = Arc::new(beava_server::idem_cache::IdemCache::new()); + AppState::new(dev_agg, wal_sink, idem_cache) +} + +fn measure_legacy_lock_hold(app_state: &AppState) -> Duration { + let lock_start = Instant::now(); + let _entries: Vec<(EntityKey, Vec)> = { + let tables = app_state.dev_agg.state_tables.lock(); + tables[0] + .iter_sorted() + .map(|(k, v)| (k.clone(), v.clone())) + .collect() + }; + lock_start.elapsed() +} + +#[cfg(unix)] +fn measure_fork_parent_lock_hold(app_state: &AppState) -> Duration { + let lock_start = Instant::now(); + let state_lock = app_state.dev_agg.state_tables.lock(); + let pid = unsafe { libc::fork() }; + let lock_held = lock_start.elapsed(); + if pid == 0 { + unsafe { libc::_exit(0) }; + } + assert!(pid > 0, "fork failed: {}", std::io::Error::last_os_error()); + drop(state_lock); + let mut status: libc::c_int = 0; + unsafe { + libc::waitpid(pid, &mut status, 0); + } + lock_held +} + +fn build_body(n_entities: usize) -> SnapshotBody { + let mut entries: Vec<(EntityKey, Vec)> = Vec::with_capacity(n_entities); + for ent in 0..n_entities { + let key_str = format!("user_{ent:09}"); + let entity_key = EntityKey(smallvec![( + CompactString::from("user_id"), + Value::Str(CompactString::from(key_str.as_str())), + )]); + entries.push((entity_key, vec![AggOp::Count(CountState { n: ent as u64 })])); + } + let mut state_tables: SerializedStateTables = BTreeMap::new(); + state_tables.insert("agg_0".to_string(), entries); + SnapshotBody { + body_format_version: SNAPSHOT_BODY_FORMAT_VERSION, + registry: RegistryDescriptorsOnly::default(), + state_tables, + next_event_id: 0, + query_time_ms: 0, + } +} + +// ─── Legacy lock-hold at big N ────────────────────────────────────────────── + +#[cfg(unix)] +#[tokio::test(flavor = "current_thread")] +#[ignore = "big-state: builds ~1GB of state; run with --ignored --release"] +async fn legacy_lock_hold_at_1m_entries() { + let app_state = build_app_state(1_000_000); + let _ = measure_legacy_lock_hold(&app_state); // warm-up + let mut samples: Vec = (0..3) + .map(|_| measure_legacy_lock_hold(&app_state).as_secs_f64() * 1000.0) + .collect(); + samples.sort_by(|a, b| a.partial_cmp(b).unwrap()); + let lock_ms = samples[1]; + println!(); + println!("legacy lock-hold @ N=1M: {lock_ms:.1}ms"); + // 1M Count entries should hold the lock for ≥500ms in release, ≥1s in + // debug. Loose floor (100ms) — the point is to prove the lock IS held + // for a long time at production scale. + assert!( + lock_ms >= 100.0, + "legacy lock-hold at 1M entries should be ≥100ms — got {lock_ms:.1}ms" + ); +} + +#[cfg(unix)] +#[tokio::test(flavor = "current_thread")] +#[ignore = "big-state: builds ~2GB of state; run with --ignored --release"] +async fn legacy_lock_hold_at_5m_entries() { + // 5M entries ≈ the incident's apparent scale (~507 MB encoded / + // ~100 B per entry encoded → ~5M entries). + let app_state = build_app_state(5_000_000); + let _ = measure_legacy_lock_hold(&app_state); + let mut samples: Vec = (0..3) + .map(|_| measure_legacy_lock_hold(&app_state).as_secs_f64() * 1000.0) + .collect(); + samples.sort_by(|a, b| a.partial_cmp(b).unwrap()); + let lock_ms = samples[1]; + println!(); + println!( + "legacy lock-hold @ N=5M: {lock_ms:.1}ms ({:.1}s)", + lock_ms / 1000.0 + ); + // 5M Count entries — legacy should be in the seconds. This number is + // the smoking gun for the incident: the lock is held for longer than + // a 3s docker healthcheck timeout under any non-trivial state. + assert!( + lock_ms >= 500.0, + "legacy lock-hold at 5M entries should be ≥500ms — got {lock_ms:.1}ms" + ); +} + +// ─── Fork lock-hold at big N (must stay sub-millisecond) ──────────────────── + +#[cfg(unix)] +#[tokio::test(flavor = "current_thread")] +#[ignore = "big-state: builds ~1GB of state; run with --ignored --release"] +async fn fork_lock_hold_at_1m_entries() { + let app_state = build_app_state(1_000_000); + let _ = measure_fork_parent_lock_hold(&app_state); // warm-up + let mut samples: Vec = (0..3) + .map(|_| measure_fork_parent_lock_hold(&app_state).as_secs_f64() * 1000.0) + .collect(); + samples.sort_by(|a, b| a.partial_cmp(b).unwrap()); + let lock_ms = samples[1]; + println!(); + println!("fork lock-hold @ N=1M: {lock_ms:.2}ms"); + // Fork is O(1) — state size doesn't matter. Generous 100ms ceiling + // for CI variance; empirically sub-millisecond. + assert!( + lock_ms < 100.0, + "fork lock-hold at 1M entries must be O(1) — got {lock_ms:.2}ms" + ); +} + +#[cfg(unix)] +#[tokio::test(flavor = "current_thread")] +#[ignore = "big-state: builds ~2GB of state; run with --ignored --release"] +async fn fork_lock_hold_at_5m_entries() { + let app_state = build_app_state(5_000_000); + let _ = measure_fork_parent_lock_hold(&app_state); + let mut samples: Vec = (0..3) + .map(|_| measure_fork_parent_lock_hold(&app_state).as_secs_f64() * 1000.0) + .collect(); + samples.sort_by(|a, b| a.partial_cmp(b).unwrap()); + let lock_ms = samples[1]; + println!(); + println!("fork lock-hold @ N=5M: {lock_ms:.2}ms"); + // The key invariant: even at 5M entries, fork releases the lock in + // milliseconds. (libc::fork's page-table copy on Linux scales weakly + // with VM size, but should still be well under 100ms at this RAM size + // on modern hardware.) + assert!( + lock_ms < 100.0, + "fork lock-hold at 5M entries must be O(1) — got {lock_ms:.2}ms" + ); +} + +// ─── Side-by-side speedup at production scale ─────────────────────────────── + +#[cfg(unix)] +#[tokio::test(flavor = "current_thread")] +#[ignore = "big-state: builds ~1GB of state; run with --ignored --release"] +async fn fork_speedup_at_1m_entries() { + let app_state = build_app_state(1_000_000); + let _ = measure_legacy_lock_hold(&app_state); + let _ = measure_fork_parent_lock_hold(&app_state); + + let mut legacy: Vec = (0..3) + .map(|_| measure_legacy_lock_hold(&app_state).as_secs_f64() * 1000.0) + .collect(); + let mut fork: Vec = (0..3) + .map(|_| measure_fork_parent_lock_hold(&app_state).as_secs_f64() * 1000.0) + .collect(); + legacy.sort_by(|a, b| a.partial_cmp(b).unwrap()); + fork.sort_by(|a, b| a.partial_cmp(b).unwrap()); + + let legacy_ms = legacy[1]; + let fork_ms = fork[1]; + let speedup = legacy_ms / fork_ms.max(0.001); + + println!(); + println!("=== Lock-hold speedup at N=1M entities (production-scale) ==="); + println!(" legacy: {legacy_ms:>8.1}ms"); + println!(" fork: {fork_ms:>8.2}ms"); + println!(" speedup: {speedup:>6.0}×"); + println!(); + + // Speedup at 1M is empirically 50-1000× depending on OS memory state + // (fork's page-table copy scales weakly with VM size after the runner + // has already allocated/freed large state in earlier tests). 20× is + // the CI floor — anything higher means the bug is fixed; the exact + // multiplier doesn't matter beyond that. + assert!( + speedup >= 20.0, + "speedup at 1M entries must be ≥20× — got {speedup:.0}× (legacy={legacy_ms}ms fork={fork_ms}ms)" + ); +} + +// ─── Recovery decode at big N ──────────────────────────────────────────────── + +#[test] +#[ignore = "big-state: ~100 MB encoded snapshot; run with --ignored --release"] +fn recovery_decode_at_1m_entries() { + let tmp = TempDir::new().unwrap(); + let body = build_body(1_000_000); + let encoded = body.encode().expect("encode"); + let body_mb = encoded.len() as f64 / (1024.0 * 1024.0); + SnapshotWriter::write(tmp.path(), 1, 0, &encoded).unwrap(); + let path = tmp.path().join(format!("snapshot-{:016x}.bvs", 1u64)); + + // Median of 3 to smooth fs cache effects. + let mut samples: Vec<(f64, f64)> = Vec::with_capacity(3); + for _ in 0..3 { + let t0 = Instant::now(); + let (_h, bytes) = SnapshotReader::open(&path).unwrap(); + let open_ms = t0.elapsed().as_secs_f64() * 1000.0; + let t1 = Instant::now(); + let _decoded = SnapshotBody::decode(&bytes).unwrap(); + let decode_ms = t1.elapsed().as_secs_f64() * 1000.0; + samples.push((open_ms, decode_ms)); + } + samples.sort_by(|a, b| a.1.partial_cmp(&b.1).unwrap()); + let (open_ms, decode_ms) = samples[1]; + let mb_per_s = body_mb / (decode_ms / 1000.0); + + println!(); + println!("=== Recovery decode @ N=1M entries ==="); + println!(" encoded: {body_mb:>7.1} MB"); + println!(" open: {open_ms:>7.2} ms"); + println!(" decode: {decode_ms:>7.2} ms"); + println!(" throughput: {mb_per_s:>7.1} MB/s"); +} + +#[test] +#[ignore = "big-state: ~500 MB encoded snapshot — matches incident; run with --ignored --release"] +fn recovery_decode_at_5m_entries() { + // Approx the incident's 507 MB snapshot size. + let tmp = TempDir::new().unwrap(); + let body = build_body(5_000_000); + let encoded = body.encode().expect("encode"); + let body_mb = encoded.len() as f64 / (1024.0 * 1024.0); + SnapshotWriter::write(tmp.path(), 1, 0, &encoded).unwrap(); + let path = tmp.path().join(format!("snapshot-{:016x}.bvs", 1u64)); + + // Single pass — encoding 5M entries once is expensive enough. + let t0 = Instant::now(); + let (_h, bytes) = SnapshotReader::open(&path).unwrap(); + let open_ms = t0.elapsed().as_secs_f64() * 1000.0; + let t1 = Instant::now(); + let _decoded = SnapshotBody::decode(&bytes).unwrap(); + let decode_ms = t1.elapsed().as_secs_f64() * 1000.0; + let mb_per_s = body_mb / (decode_ms / 1000.0); + + println!(); + println!("=== Recovery decode @ N=5M entries (incident scale) ==="); + println!(" encoded: {body_mb:>7.1} MB"); + println!(" open: {open_ms:>7.2} ms"); + println!( + " decode: {decode_ms:>7.2} ms ({:.2}s)", + decode_ms / 1000.0 + ); + println!(" throughput: {mb_per_s:>7.1} MB/s"); + println!(); + println!("This is roughly the wall-clock cost of boot-time recovery on"); + println!("the production deployment. Apply (install_from_descriptors +"); + println!("per-table HashMap rebuild) adds further overhead not measured"); + println!("here."); +} + +// ─── End-to-end fork snapshot at big N ────────────────────────────────────── + +#[cfg(unix)] +#[tokio::test(flavor = "multi_thread", worker_threads = 2)] +#[ignore = "big-state: full fork snapshot at production scale; run with --ignored --release"] +async fn fork_full_snapshot_at_1m_entries() { + let tmp = TempDir::new().unwrap(); + let app_state = build_app_state(1_000_000); + + let t0 = Instant::now(); + let exit = do_snapshot_via_fork(tmp.path(), 1, &app_state) + .await + .expect("fork-snapshot"); + let parent_elapsed = t0.elapsed(); + let exit_str = match exit { + beava_server::snapshot_fork::ChildExit::Success { .. } => "success".to_string(), + beava_server::snapshot_fork::ChildExit::Failure { code, message } => { + format!("FAIL code={code} message={message}") + } + }; + + println!(); + println!("=== Full fork snapshot @ N=1M entities ==="); + println!( + " parent wall-clock: {:.1}ms", + parent_elapsed.as_secs_f64() * 1000.0 + ); + println!(" child exit: {exit_str}"); + println!(); + println!("The parent's apply lock was held only across the fork syscall"); + println!("(measured separately, ~0.5ms). Everything else is child work +"); + println!("waitpid; the apply thread was free to serve traffic throughout."); +} diff --git a/crates/beava-server/tests/snapshot_conditional.rs b/crates/beava-server/tests/snapshot_conditional.rs new file mode 100644 index 00000000..d94283e5 --- /dev/null +++ b/crates/beava-server/tests/snapshot_conditional.rs @@ -0,0 +1,448 @@ +//! Redis-style conditional snapshot tests. +//! +//! With `BEAVA_SNAPSHOT_MIN_EVENTS=N` (or `SnapshotTaskConfig +//! { min_events_per_snapshot: N, .. }`), an interval tick skips +//! snapshotting unless at least N WAL events have committed since the +//! previous successful snapshot. Mirrors Redis's `save N M` directive. +//! +//! Tests: +//! - `default_zero_threshold_always_snapshots_on_tick` +//! When threshold is 0 (legacy default), every interval tick produces a +//! snapshot, even with zero WAL activity. +//! - `nonzero_threshold_skips_when_below` +//! With threshold > 0 and no WAL events, no snapshot file is produced. +//! - `nonzero_threshold_fires_when_met` +//! Once enough events have been appended, the next tick produces a +//! snapshot. +//! - `manual_trigger_bypasses_threshold` +//! `force_snapshot_now` always runs regardless of threshold (operators +//! and tests need this escape hatch). +//! - `nonzero_threshold_uses_applied_data_plane_lsn` +//! Production push traffic advances the applied data-plane watermark, not +//! the legacy `WalSink` watermark. + +use beava_core::agg_descriptor::{AggregationDescriptor, NamedAggOp}; +use beava_core::agg_op::{AggKind, AggOp, AggOpDescriptor, FIELD_IDX_NONE}; +use beava_core::agg_state::CountState; +use beava_core::agg_state_table::{ensure_capacity_for, AggStateTable, EntityKey}; +use beava_core::op_node::{AggSpec, OpNode}; +use beava_core::registry::{DerivationDescriptor, EventDescriptor, OutputKind, Registry}; +use beava_core::registry_diff::PayloadNode; +use beava_core::row::Value; +use beava_core::schema::{DerivedSchema, EventSchema, FieldType}; +use beava_persistence::{list_snapshots, WalSink}; +use beava_server::idem_cache::IdemCache; +use beava_server::registry_debug::DevAggState; +use beava_server::snapshot_task::{spawn_snapshot_task, SnapshotTaskConfig}; +use beava_server::AppState; +use compact_str::CompactString; +use smallvec::smallvec; +use std::collections::BTreeMap; +use std::sync::atomic::Ordering; +use std::sync::Arc; +use std::time::Duration; +use tempfile::TempDir; +use tokio::sync::oneshot; +use tokio_util::sync::CancellationToken; + +fn build_app_state() -> (AppState, WalSink, tokio::task::JoinHandle<()>) { + let registry = Arc::new(Registry::new()); + let dev_agg = DevAggState::new(registry); + let (wal_sink, wal_join) = WalSink::spawn_no_op(); + let idem_cache = Arc::new(IdemCache::new()); + let app_state = AppState::new(dev_agg, wal_sink.clone(), idem_cache); + (app_state, wal_sink, wal_join) +} + +fn count_desc() -> AggOpDescriptor { + AggOpDescriptor { + kind: AggKind::Count, + field: None, + window_ms: None, + where_expr: None, + n: None, + half_life_ms: None, + sub_window_ms: None, + sigma: None, + sketch_params: None, + ext: Default::default(), + field_idx: FIELD_IDX_NONE, + field_idx_into_event_extracted: Vec::new(), + } +} + +fn build_registered_app_state( + n_entities: usize, +) -> (AppState, WalSink, tokio::task::JoinHandle<()>) { + let registry = Arc::new(Registry::new()); + + let mut event_fields = BTreeMap::new(); + event_fields.insert("user_id".to_string(), FieldType::Str); + let event = EventDescriptor { + name: "Txn".to_string(), + schema: EventSchema { + fields: event_fields, + optional_fields: vec![], + }, + dedupe_key: None, + dedupe_window_ms: None, + keep_events_for_ms: None, + cold_after_ms: None, + registered_at_version: 0, + name_arc: Arc::from(""), + apply_field_names: vec![], + }; + + let mut group_by = BTreeMap::new(); + group_by.insert( + "cnt".to_string(), + AggSpec { + op: "count".to_string(), + params: serde_json::Value::Object(Default::default()), + }, + ); + let mut derived_fields = BTreeMap::new(); + derived_fields.insert("user_id".to_string(), FieldType::Str); + derived_fields.insert("cnt".to_string(), FieldType::I64); + let deriv = DerivationDescriptor { + name: "UserCounts".to_string(), + output_kind: OutputKind::Table, + upstreams: vec!["Txn".to_string()], + ops: vec![OpNode::GroupBy { + keys: vec!["user_id".to_string()], + agg: group_by, + }], + schema: DerivedSchema { + fields: derived_fields, + optional_fields: vec![], + }, + table_primary_key: Some(vec!["user_id".to_string()]), + registered_at_version: 0, + }; + let agg = AggregationDescriptor { + node_name: "UserCounts".to_string(), + source_node_name: "Txn".to_string(), + group_keys: vec!["user_id".to_string()], + features: vec![NamedAggOp { + feature_name: "cnt".to_string(), + descriptor: count_desc(), + }], + agg_id: 0, + field_names: vec![], + cluster_id: 0, + }; + + registry.apply_registration( + vec![PayloadNode::Event(event), PayloadNode::Derivation(deriv)], + vec![], + vec![], + vec![("UserCounts".to_string(), Arc::new(agg))], + ); + + let dev_agg = DevAggState::new(registry); + { + let mut tables = dev_agg.state_tables.lock(); + ensure_capacity_for(&mut tables, 1); + let mut table = AggStateTable::new(); + for ent in 0..n_entities { + let key_str = format!("user_{ent:09}"); + let entity_key = EntityKey(smallvec![( + CompactString::from("user_id"), + Value::Str(CompactString::from(key_str.as_str())), + )]); + table.insert_from_entity_key( + entity_key, + vec![AggOp::Count(CountState { n: ent as u64 })], + ); + } + tables[0] = table; + } + + let (wal_sink, wal_join) = WalSink::spawn_no_op(); + let idem_cache = Arc::new(IdemCache::new()); + let app_state = AppState::new(dev_agg, wal_sink.clone(), idem_cache); + (app_state, wal_sink, wal_join) +} + +fn snapshot_count(dir: &std::path::Path) -> usize { + list_snapshots(dir).map(|v| v.len()).unwrap_or(0) +} + +/// Snapshot interval used by these tests — short so the test completes +/// quickly while still letting us observe 2-3 ticks. +const TICK_MS: u64 = 100; + +#[tokio::test(flavor = "current_thread")] +async fn default_zero_threshold_always_snapshots_on_tick() { + let tmp = TempDir::new().unwrap(); + let (app_state, wal_sink, _wal_join) = build_app_state(); + + let cfg = SnapshotTaskConfig { + interval: Duration::from_millis(TICK_MS), + snapshot_dir: tmp.path().to_path_buf(), + retain: 10, + min_events_per_snapshot: 0, // legacy behavior + use_fork_snapshot: false, + snapshot_lsn_capture_tx: None, + }; + let cancel = CancellationToken::new(); + let (snap_join, _trigger) = + spawn_snapshot_task(cfg, Arc::new(app_state), wal_sink, None, cancel.clone()); + + // Wait for ~3 ticks. With threshold=0, each tick produces a snapshot. + // Note: with no WAL activity, all snapshots write to the same LSN-named + // file (`snapshot-{lsn:016x}.bvs`), so multiple ticks overwrite the + // same file. We only assert >=1 — the contract is "every tick fires", + // not "every tick produces a unique file". + tokio::time::sleep(Duration::from_millis(TICK_MS * 4)).await; + cancel.cancel(); + let _ = snap_join.await; + + let n = snapshot_count(tmp.path()); + assert!( + n >= 1, + "with threshold=0, at least one snapshot must be written — got {n}" + ); +} + +#[tokio::test(flavor = "current_thread")] +async fn nonzero_threshold_skips_when_below() { + let tmp = TempDir::new().unwrap(); + let (app_state, wal_sink, _wal_join) = build_app_state(); + + let cfg = SnapshotTaskConfig { + interval: Duration::from_millis(TICK_MS), + snapshot_dir: tmp.path().to_path_buf(), + retain: 10, + min_events_per_snapshot: 1000, // anything > 0 events appended + use_fork_snapshot: false, + snapshot_lsn_capture_tx: None, + }; + let cancel = CancellationToken::new(); + let (snap_join, _trigger) = + spawn_snapshot_task(cfg, Arc::new(app_state), wal_sink, None, cancel.clone()); + + // Same wait as the previous test — but with threshold > 0 and zero + // WAL appends, every tick should be skipped. + tokio::time::sleep(Duration::from_millis(TICK_MS * 4)).await; + cancel.cancel(); + let _ = snap_join.await; + + let n = snapshot_count(tmp.path()); + assert_eq!( + n, 0, + "with threshold=1000 and zero appends, no snapshot should be written — got {n}" + ); +} + +#[tokio::test(flavor = "current_thread")] +async fn nonzero_threshold_fires_when_met() { + let tmp = TempDir::new().unwrap(); + let (app_state, wal_sink, _wal_join) = build_app_state(); + + let cfg = SnapshotTaskConfig { + interval: Duration::from_millis(TICK_MS), + snapshot_dir: tmp.path().to_path_buf(), + retain: 10, + // Low threshold so a handful of appends clears it. + min_events_per_snapshot: 3, + use_fork_snapshot: false, + snapshot_lsn_capture_tx: None, + }; + let cancel = CancellationToken::new(); + let app_state_arc = Arc::new(app_state); + let (snap_join, _trigger) = spawn_snapshot_task( + cfg, + app_state_arc.clone(), + wal_sink.clone(), + None, + cancel.clone(), + ); + + // Append 5 events — clears the threshold of 3. + for _ in 0..5 { + wal_sink + .append_event(b"{}".to_vec()) + .await + .expect("append_event"); + } + + // Wait for ~3 ticks. At least one should fire. + tokio::time::sleep(Duration::from_millis(TICK_MS * 4)).await; + cancel.cancel(); + let _ = snap_join.await; + + let n = snapshot_count(tmp.path()); + assert!( + n >= 1, + "threshold=3 met by 5 appends — at least 1 snapshot expected, got {n}" + ); + // After a snapshot fires, last_snapshot_lsn updates so further ticks + // with no new appends should NOT fire. We don't strictly assert the + // exact count (timing-sensitive) but the test above proves the skip + // path works. +} + +#[tokio::test(flavor = "current_thread")] +async fn nonzero_threshold_uses_applied_data_plane_lsn() { + let tmp = TempDir::new().unwrap(); + let (app_state, wal_sink, _wal_join) = build_registered_app_state(10); + + let cfg = SnapshotTaskConfig { + interval: Duration::from_millis(TICK_MS), + snapshot_dir: tmp.path().to_path_buf(), + retain: 10, + min_events_per_snapshot: 3, + use_fork_snapshot: false, + snapshot_lsn_capture_tx: None, + }; + let cancel = CancellationToken::new(); + let app_state = Arc::new(app_state); + let (snap_join, _trigger) = + spawn_snapshot_task(cfg, Arc::clone(&app_state), wal_sink, None, cancel.clone()); + + tokio::time::sleep(Duration::from_millis(TICK_MS / 2)).await; + app_state.dev_agg.next_event_id.store(5, Ordering::Release); + tokio::time::sleep(Duration::from_millis(TICK_MS * 4)).await; + cancel.cancel(); + let _ = snap_join.await; + + let lsns: Vec = list_snapshots(tmp.path()) + .expect("list snapshots") + .into_iter() + .map(|(lsn, _)| lsn) + .collect(); + assert!( + lsns.contains(&5), + "data-plane applied watermark should trigger snapshot at LSN 5; got {lsns:?}" + ); +} + +#[tokio::test(flavor = "current_thread")] +async fn manual_trigger_bypasses_threshold() { + let tmp = TempDir::new().unwrap(); + let (app_state, wal_sink, _wal_join) = build_app_state(); + + let cfg = SnapshotTaskConfig { + // Long interval so the periodic tick effectively never fires in + // the test window — we only exercise the manual trigger path. + interval: Duration::from_secs(3600), + snapshot_dir: tmp.path().to_path_buf(), + retain: 10, + // High threshold — would skip any interval tick even if it fired. + min_events_per_snapshot: u64::MAX, + use_fork_snapshot: false, + snapshot_lsn_capture_tx: None, + }; + let cancel = CancellationToken::new(); + let (snap_join, trigger) = + spawn_snapshot_task(cfg, Arc::new(app_state), wal_sink, None, cancel.clone()); + + // Fire a manual trigger — should always run regardless of threshold. + let (ack_tx, ack_rx) = oneshot::channel(); + trigger.send(ack_tx).await.expect("trigger send"); + let result = ack_rx.await.expect("ack"); + assert!(result.is_ok(), "manual snapshot should succeed: {result:?}"); + + cancel.cancel(); + let _ = snap_join.await; + + let n = snapshot_count(tmp.path()); + assert!( + n >= 1, + "manual trigger should always produce a snapshot — got {n}" + ); +} + +#[tokio::test(flavor = "multi_thread", worker_threads = 4)] +async fn snapshot_baseline_stays_at_captured_lsn_when_wal_advances_during_write() { + let tmp = TempDir::new().unwrap(); + let (app_state, wal_sink, _wal_join) = build_registered_app_state(10); + + for _ in 0..5 { + wal_sink + .append_event(b"before".to_vec()) + .await + .expect("append before snapshot"); + } + + let (capture_tx, capture_rx) = std::sync::mpsc::channel(); + let cfg = SnapshotTaskConfig { + interval: Duration::from_millis(TICK_MS), + snapshot_dir: tmp.path().to_path_buf(), + retain: 10, + min_events_per_snapshot: 5, + use_fork_snapshot: false, + snapshot_lsn_capture_tx: Some(capture_tx), + }; + let cancel = CancellationToken::new(); + let app_state = Arc::new(app_state); + let (snap_join, trigger) = spawn_snapshot_task( + cfg, + Arc::clone(&app_state), + wal_sink.clone(), + None, + cancel.clone(), + ); + + let tables = Arc::clone(&app_state.dev_agg.state_tables); + let (locked_tx, locked_rx) = std::sync::mpsc::channel(); + let (release_tx, release_rx) = std::sync::mpsc::channel(); + let lock_thread = std::thread::spawn(move || { + let _guard = tables.lock(); + let _ = locked_tx.send(()); + let _ = release_rx.recv(); + }); + locked_rx + .recv_timeout(Duration::from_secs(2)) + .expect("test lock holder acquired state_tables"); + + let (ack_tx, ack_rx) = oneshot::channel(); + trigger.send(ack_tx).await.expect("trigger send"); + + // Wait until the snapshot task has captured snapshot_lsn=5 and is about + // to block on `state_tables.lock()`. It cannot serialize until this test + // releases the lock. + assert_eq!( + capture_rx + .recv_timeout(Duration::from_secs(2)) + .expect("snapshot task did not capture LSN before lock"), + 5 + ); + + for _ in 0..5 { + wal_sink + .append_event(b"during".to_vec()) + .await + .expect("append during snapshot"); + } + release_tx.send(()).expect("release test lock holder"); + + let result = tokio::time::timeout(Duration::from_secs(5), ack_rx) + .await + .expect("manual snapshot ack timed out") + .expect("ack"); + assert!(result.is_ok(), "manual snapshot should succeed: {result:?}"); + lock_thread.join().expect("lock holder thread"); + + tokio::time::sleep(Duration::from_millis(TICK_MS * 3)).await; + cancel.cancel(); + let _ = snap_join.await; + + let lsns: Vec = list_snapshots(tmp.path()) + .expect("list snapshots") + .into_iter() + .map(|(lsn, _)| lsn) + .collect(); + assert!( + lsns.contains(&5) && lsns.contains(&10), + "expected snapshots at captured LSN 5 and later LSN 10; got {lsns:?}" + ); +} + +// NOTE: env-parsing unit test was previously here but violated the Phase +// 13.5.3 architectural rule (`phase13_5_3_no_env_var_pokes_in_tests`). +// `BEAVA_SNAPSHOT_MIN_EVENTS` is read once at boot in `server.rs` via +// `snapshot_task::min_events_from_env()`; tests construct +// `SnapshotTaskConfig` with `min_events_per_snapshot` set directly (see +// the four tests above) rather than poking the global process env. diff --git a/crates/beava-server/tests/snapshot_fork.rs b/crates/beava-server/tests/snapshot_fork.rs new file mode 100644 index 00000000..4a505ea5 --- /dev/null +++ b/crates/beava-server/tests/snapshot_fork.rs @@ -0,0 +1,242 @@ +//! Integration tests for the fork()+COW snapshot path. +//! +//! These tests verify the contract documented in +//! `crates/beava-server/src/snapshot_fork.rs`: +//! +//! 1. `do_snapshot_via_fork` produces a snapshot file decodable by the +//! existing `SnapshotReader` (byte-identical schema to the in-process +//! path). +//! 2. The child path does not corrupt parent state (parent can continue +//! using `app_state` after the fork without crashing). +//! 3. The fork path serializes real registered aggregation state. +//! +//! NOTE on lock-hold timing: a microbenchmark proving "lock held < 10ms" +//! is intentionally NOT included here — it's timing-sensitive and would +//! flake in CI. The qualitative claim is locked in by inspection of the +//! `snapshot_fork.rs` source (the lock guard scope wraps only the fork +//! syscall) and the parent-state-after-fork test below (which would fail +//! if the parent were blocked on a long lock-hold). + +use beava_core::agg_descriptor::{AggregationDescriptor, NamedAggOp}; +use beava_core::agg_op::{AggKind, AggOp, AggOpDescriptor, FIELD_IDX_NONE}; +use beava_core::agg_state::CountState; +use beava_core::agg_state_table::{ensure_capacity_for, AggStateTable, EntityKey}; +use beava_core::op_node::{AggSpec, OpNode}; +use beava_core::registry::{DerivationDescriptor, EventDescriptor, OutputKind, Registry}; +use beava_core::registry_diff::PayloadNode; +use beava_core::row::Value; +use beava_core::schema::{DerivedSchema, EventSchema, FieldType}; +use beava_core::snapshot_body::SnapshotBody; +use beava_persistence::SnapshotReader; +use beava_server::registry_debug::DevAggState; +use beava_server::snapshot_fork::{do_snapshot_via_fork, ChildExit}; +use beava_server::AppState; +use compact_str::CompactString; +use smallvec::smallvec; +use std::collections::BTreeMap; +use std::sync::atomic::Ordering; +use std::sync::Arc; +use tempfile::TempDir; + +fn count_desc() -> AggOpDescriptor { + AggOpDescriptor { + kind: AggKind::Count, + field: None, + window_ms: None, + where_expr: None, + n: None, + half_life_ms: None, + sub_window_ms: None, + sigma: None, + sketch_params: None, + ext: Default::default(), + field_idx: FIELD_IDX_NONE, + field_idx_into_event_extracted: Vec::new(), + } +} + +/// Build a minimal `AppState` populated with N entities × 1 Count aggregation. +fn build_app_state(n_entities: usize) -> AppState { + let registry = Arc::new(Registry::new()); + let mut event_fields = BTreeMap::new(); + event_fields.insert("user_id".to_string(), FieldType::Str); + let event = EventDescriptor { + name: "Txn".to_string(), + schema: EventSchema { + fields: event_fields, + optional_fields: vec![], + }, + dedupe_key: None, + dedupe_window_ms: None, + keep_events_for_ms: None, + cold_after_ms: None, + registered_at_version: 0, + name_arc: Arc::from(""), + apply_field_names: vec![], + }; + + let mut group_by = BTreeMap::new(); + group_by.insert( + "cnt".to_string(), + AggSpec { + op: "count".to_string(), + params: serde_json::Value::Object(Default::default()), + }, + ); + let mut derived_fields = BTreeMap::new(); + derived_fields.insert("user_id".to_string(), FieldType::Str); + derived_fields.insert("cnt".to_string(), FieldType::I64); + let deriv = DerivationDescriptor { + name: "UserCounts".to_string(), + output_kind: OutputKind::Table, + upstreams: vec!["Txn".to_string()], + ops: vec![OpNode::GroupBy { + keys: vec!["user_id".to_string()], + agg: group_by, + }], + schema: DerivedSchema { + fields: derived_fields, + optional_fields: vec![], + }, + table_primary_key: Some(vec!["user_id".to_string()]), + registered_at_version: 0, + }; + let agg = AggregationDescriptor { + node_name: "UserCounts".to_string(), + source_node_name: "Txn".to_string(), + group_keys: vec!["user_id".to_string()], + features: vec![NamedAggOp { + feature_name: "cnt".to_string(), + descriptor: count_desc(), + }], + agg_id: 0, + field_names: vec![], + cluster_id: 0, + }; + registry.apply_registration( + vec![PayloadNode::Event(event), PayloadNode::Derivation(deriv)], + vec![], + vec![], + vec![("UserCounts".to_string(), Arc::new(agg))], + ); + + let dev_agg = DevAggState::new(registry); + + { + let mut tables = dev_agg.state_tables.lock(); + ensure_capacity_for(&mut tables, 1); + let mut table = AggStateTable::new(); + for ent in 0..n_entities { + let key_str = format!("user_{ent:09}"); + let entity_key = EntityKey(smallvec![( + CompactString::from("user_id"), + Value::Str(CompactString::from(key_str.as_str())), + )]); + table.insert_from_entity_key( + entity_key, + vec![AggOp::Count(CountState { n: ent as u64 })], + ); + } + tables[0] = table; + } + + // Build a no-op WalSink for this test — the snapshot path doesn't need + // WAL durability. + let (wal_sink, _wal_join) = beava_persistence::WalSink::spawn_no_op(); + + let idem_cache = Arc::new(beava_server::idem_cache::IdemCache::new()); + AppState::new(dev_agg, wal_sink, idem_cache) +} + +// NOTE: env-gate test was previously here but violated the Phase 13.5.3 +// architectural rule (`phase13_5_3_no_env_var_pokes_in_tests`) — process-env +// pokes pollute parallel test runs. Production reads `BEAVA_SNAPSHOT_FORK` +// once at boot in `server.rs` via `snapshot_fork::fork_enabled()`; tests +// drive the fork path by calling `do_snapshot_via_fork` directly (below) +// or by setting `SnapshotTaskConfig.use_fork_snapshot = true` (see +// `tests/snapshot_conditional.rs`). + +#[cfg(unix)] +#[tokio::test(flavor = "current_thread")] +async fn fork_snapshot_writes_decodable_file() { + let tmp = TempDir::new().unwrap(); + let app_state = build_app_state(100); + + let exit = do_snapshot_via_fork(tmp.path(), 42, &app_state) + .await + .expect("fork-snapshot must not error"); + + match exit { + ChildExit::Success { .. } => {} + ChildExit::Failure { code, message } => { + panic!("child failed: code={code} message={message}"); + } + } + + // File should exist with the expected name. + let path = tmp.path().join(format!("snapshot-{:016x}.bvs", 42u64)); + assert!(path.exists(), "snapshot file must exist at {path:?}"); + + // And decode cleanly. + let (header, body) = SnapshotReader::open(&path).expect("snapshot must decode"); + assert_eq!(header.snapshot_lsn, 42); + // body_len must match the actual body bytes count. + assert_eq!(header.body_len as usize, body.len()); + // SnapshotBody must decode and contain the registered aggregation state. + let decoded = SnapshotBody::decode(&body).expect("body must decode"); + let entries = decoded + .state_tables + .get("UserCounts") + .expect("registered aggregation state must be serialized"); + assert_eq!(entries.len(), 100); +} + +#[cfg(unix)] +#[tokio::test(flavor = "current_thread")] +async fn fork_snapshot_parent_state_intact() { + let tmp = TempDir::new().unwrap(); + let app_state = build_app_state(50); + let pre_event_id = app_state.dev_agg.next_event_id.load(Ordering::Relaxed); + + let _ = do_snapshot_via_fork(tmp.path(), 1, &app_state) + .await + .expect("fork-snapshot must not error"); + + // Parent must still be able to use app_state after fork. + let post_event_id = app_state.dev_agg.next_event_id.load(Ordering::Relaxed); + assert_eq!(pre_event_id, post_event_id); + + // The state_tables Mutex must still be lockable in the parent — the fork + // only briefly held it across the syscall and dropped immediately. + let _guard = app_state.dev_agg.state_tables.lock(); + // If we got the lock without deadlock, the parent is healthy. +} + +#[cfg(unix)] +#[tokio::test(flavor = "current_thread")] +async fn fork_snapshot_with_zero_state() { + // Edge case: snapshot an empty state. Must still produce a decodable file. + let tmp = TempDir::new().unwrap(); + let app_state = build_app_state(0); + + let exit = do_snapshot_via_fork(tmp.path(), 7, &app_state) + .await + .unwrap(); + assert!(matches!(exit, ChildExit::Success { .. })); + + let path = tmp.path().join(format!("snapshot-{:016x}.bvs", 7u64)); + let (header, body) = SnapshotReader::open(&path).expect("zero-state snapshot must decode"); + assert_eq!(header.snapshot_lsn, 7); + let decoded = SnapshotBody::decode(&body).expect("zero-state body must decode"); + assert_eq!( + decoded.state_tables["UserCounts"].len(), + 0, + "registered aggregation with zero entities should serialize as an empty table" + ); +} + +// Suppress unused-import warning in non-unix builds. +#[cfg(not(unix))] +fn _force_uses() { + let _: Option<&AppState> = None; +} diff --git a/crates/beava-server/tests/snapshot_fork_extreme.rs b/crates/beava-server/tests/snapshot_fork_extreme.rs new file mode 100644 index 00000000..1d55c64f --- /dev/null +++ b/crates/beava-server/tests/snapshot_fork_extreme.rs @@ -0,0 +1,187 @@ +//! Extreme-scale fork() sweep — 30M to 50M entries, beyond what beava +//! recommends per-instance, to characterize fork() linear scaling and +//! compare against Redis's published numbers. +//! +//! Memory budget: ~15 GB peak at 50M entries. macOS will swap if you're +//! tight on RAM; run on a 32 GB+ machine. +//! +//! Run: +//! +//! ```sh +//! cargo test --release -p beava-server --test snapshot_fork_extreme \ +//! fork_at_extreme_scale -- --ignored --nocapture +//! ``` + +use beava_core::agg_op::AggOp; +use beava_core::agg_state::CountState; +use beava_core::agg_state_table::{AggStateTable, EntityKey}; +use beava_core::registry::Registry; +use beava_core::row::Value; +use beava_server::registry_debug::DevAggState; +use beava_server::AppState; +use compact_str::CompactString; +use smallvec::smallvec; +use std::sync::Arc; +use std::time::{Duration, Instant}; + +fn build_app_state(n_entities: usize) -> AppState { + let registry = Arc::new(Registry::new()); + let dev_agg = DevAggState::new(registry); + { + let mut tables = dev_agg.state_tables.lock(); + let mut table = AggStateTable::new(); + for ent in 0..n_entities { + let key_str = format!("user_{ent:09}"); + let entity_key = EntityKey(smallvec![( + CompactString::from("user_id"), + Value::Str(CompactString::from(key_str.as_str())), + )]); + table.insert_from_entity_key( + entity_key, + vec![AggOp::Count(CountState { n: ent as u64 })], + ); + } + tables.push(table); + } + let (wal_sink, _wal_join) = beava_persistence::WalSink::spawn_no_op(); + let idem_cache = Arc::new(beava_server::idem_cache::IdemCache::new()); + AppState::new(dev_agg, wal_sink, idem_cache) +} + +#[cfg(unix)] +fn measure_fork(app_state: &AppState) -> Duration { + let lock_start = Instant::now(); + let state_lock = app_state.dev_agg.state_tables.lock(); + let pid = unsafe { libc::fork() }; + let lock_held = lock_start.elapsed(); + if pid == 0 { + unsafe { libc::_exit(0) }; + } + assert!(pid > 0, "fork failed: {}", std::io::Error::last_os_error()); + drop(state_lock); + let mut status: libc::c_int = 0; + unsafe { + libc::waitpid(pid, &mut status, 0); + } + lock_held +} + +#[cfg(target_os = "macos")] +fn process_rss_mb() -> Option { + unsafe { + let mut info: libc::mach_task_basic_info = std::mem::zeroed(); + let mut count = (std::mem::size_of::() / 4) as u32; + #[allow(deprecated)] + let task = libc::mach_task_self(); + let ret = libc::task_info( + task, + libc::MACH_TASK_BASIC_INFO, + &mut info as *mut _ as *mut i32, + &mut count, + ); + if ret == 0 { + Some(info.resident_size as f64 / (1024.0 * 1024.0)) + } else { + None + } + } +} + +#[cfg(target_os = "linux")] +fn process_rss_mb() -> Option { + let statm = std::fs::read_to_string("/proc/self/statm").ok()?; + let rss_pages: u64 = statm.split_whitespace().nth(1)?.parse().ok()?; + let page_size = unsafe { libc::sysconf(libc::_SC_PAGESIZE) } as u64; + Some((rss_pages * page_size) as f64 / (1024.0 * 1024.0)) +} + +#[cfg(not(any(target_os = "macos", target_os = "linux")))] +fn process_rss_mb() -> Option { + None +} + +#[cfg(unix)] +#[tokio::test(flavor = "current_thread")] +#[ignore = "extreme: 15 GB peak; requires 32 GB+ host"] +async fn fork_at_extreme_scale() { + println!(); + println!("=== fork() at extreme beava state (30M – 50M entries) ==="); + println!( + "{:>10} {:>12} {:>14} {:>14} {:>14}", + "entries", "rss_MB", "fork_median", "fork_max", "ms_per_GB" + ); + println!("{}", "-".repeat(68)); + + // 30M is ~9 GB; 40M is ~12 GB; 50M is ~15 GB. + // Push as far as the host allows. macOS will start swapping if RAM is + // exhausted; the user should monitor `vm_stat` during the run. + let sizes = [30_000_000usize, 40_000_000, 50_000_000]; + + let mut rows: Vec<(usize, f64, f64, f64)> = Vec::new(); + + for &n in &sizes { + eprintln!("building state for N={n}..."); + let app_state = build_app_state(n); + let rss = process_rss_mb().unwrap_or(0.0); + + // Warm-up. + let _ = measure_fork(&app_state); + // 3 samples — at this scale each sample is ~25-50ms, so 3 is plenty. + let mut samples: Vec = (0..3) + .map(|_| measure_fork(&app_state).as_secs_f64() * 1000.0) + .collect(); + samples.sort_by(|a, b| a.partial_cmp(b).unwrap()); + let median = samples[samples.len() / 2]; + let max = *samples.last().unwrap(); + let ms_per_gb = if rss > 0.0 { + median / (rss / 1024.0) + } else { + 0.0 + }; + + println!( + "{:>10} {:>9.0} MB {:>11.2}ms {:>11.2}ms {:>11.2}", + n, rss, median, max, ms_per_gb + ); + rows.push((n, rss, median, ms_per_gb)); + + drop(app_state); + } + + // Show the trend explicitly. fork() should scale roughly linearly with + // RSS — confirm or refute here. + println!(); + println!("Scaling check (fork_ms / GB_rss):"); + for (n, rss_mb, fork_ms, ms_per_gb) in &rows { + println!(" N={n:>10} RSS={rss_mb:>7.0}MB fork={fork_ms:>6.2}ms → {ms_per_gb:.2} ms/GB"); + } + + println!(); + println!("=== Comparison with Redis published numbers ==="); + println!(" Apple M4 (this beava test): ~2-4 ms/GB on fresh process"); + println!(" ~15 ms/GB on long-lived process"); + println!(" Linux physical (Xeon, Redis): 9 ms/GB"); + println!(" Linux VMware VM (Redis): 12.8 ms/GB"); + println!(" AWS EC2 HVM modern (Redis): ~10 ms/GB"); + println!(" AWS EC2 Xen old (Redis): 239 ms/GB (24× worse)"); + println!(" Linode Xen small VM (Redis): 424 ms/GB (worst case)"); + println!(); + println!("Redis treats >10 ms fork as 'worth investigating' and"); + println!(">200 ms as 'a problem'. Apple M4 + beava clears the >10ms"); + println!("bar up to ~5 GB working set, then enters Redis's 'investigate'"); + println!("zone above ~10 GB — matching exactly what Redis users see."); + + // Sanity: fork should scale ROUGHLY linearly with RSS. Allow 5× tolerance + // for measurement noise + page-table-density variation. + if rows.len() >= 2 { + let (_, rss_a, fork_a, _) = rows[0]; + let (_, rss_b, fork_b, _) = rows[rows.len() - 1]; + let rss_ratio = rss_b / rss_a; + let fork_ratio = fork_b / fork_a; + println!("Linearity check: RSS grew {rss_ratio:.2}×, fork grew {fork_ratio:.2}×"); + assert!( + fork_ratio > 0.5 && fork_ratio < rss_ratio * 5.0, + "fork should scale roughly linearly with RSS — got {fork_ratio:.2}× for {rss_ratio:.2}× RSS" + ); + } +} diff --git a/crates/beava-server/tests/snapshot_fork_extreme_default.rs b/crates/beava-server/tests/snapshot_fork_extreme_default.rs new file mode 100644 index 00000000..8a9dfa1b --- /dev/null +++ b/crates/beava-server/tests/snapshot_fork_extreme_default.rs @@ -0,0 +1,117 @@ +//! Opt-in "extreme" fork test — 1M entries, asserts fork() lock-hold stays +//! under 10 ms. This is ignored by default because it allocates ~700 MB and is +//! timing-sensitive under shared CI runners. +//! +//! Lives in its own test binary so the process VM is fresh — sibling +//! tests in other files can't bloat the allocator's reserved range and +//! skew the measurement. +//! +//! Memory: ~700 MB peak. Runtime: ~1 s release, ~10 s debug. +//! +//! Why 1M (and not 5M / 10M): +//! - 1M is the "extreme" tier that remains useful as an opt-in regression +//! check without making default CI depend on 700 MB of spare memory. +//! - 5M+ requires the `--ignored --release` opt-in tests in +//! `snapshot_big_state.rs` / `snapshot_fork_scaling.rs` / +//! `snapshot_fork_extreme.rs`. +//! - The <10 ms ceiling locks in the most important production guarantee: +//! the kalshi-pulse incident (#151) class is gone for any state size up +//! to 1M entries, on any fresh-or-monotonically-growing process. + +use beava_core::agg_op::AggOp; +use beava_core::agg_state::CountState; +use beava_core::agg_state_table::{AggStateTable, EntityKey}; +use beava_core::registry::Registry; +use beava_core::row::Value; +use beava_server::registry_debug::DevAggState; +use beava_server::AppState; +use compact_str::CompactString; +use smallvec::smallvec; +use std::sync::Arc; +use std::time::{Duration, Instant}; + +fn build_app_state(n_entities: usize) -> AppState { + let registry = Arc::new(Registry::new()); + let dev_agg = DevAggState::new(registry); + { + let mut tables = dev_agg.state_tables.lock(); + let mut table = AggStateTable::new(); + for ent in 0..n_entities { + let key_str = format!("user_{ent:09}"); + let entity_key = EntityKey(smallvec![( + CompactString::from("user_id"), + Value::Str(CompactString::from(key_str.as_str())), + )]); + table.insert_from_entity_key( + entity_key, + vec![AggOp::Count(CountState { n: ent as u64 })], + ); + } + tables.push(table); + } + let (wal_sink, _wal_join) = beava_persistence::WalSink::spawn_no_op(); + let idem_cache = Arc::new(beava_server::idem_cache::IdemCache::new()); + AppState::new(dev_agg, wal_sink, idem_cache) +} + +#[cfg(unix)] +fn measure_fork(app_state: &AppState) -> Duration { + let lock_start = Instant::now(); + let state_lock = app_state.dev_agg.state_tables.lock(); + let pid = unsafe { libc::fork() }; + let lock_held = lock_start.elapsed(); + if pid == 0 { + unsafe { libc::_exit(0) }; + } + assert!(pid > 0, "fork failed: {}", std::io::Error::last_os_error()); + drop(state_lock); + let mut status: libc::c_int = 0; + unsafe { + libc::waitpid(pid, &mut status, 0); + } + lock_held +} + +#[cfg(unix)] +#[tokio::test(flavor = "current_thread")] +#[ignore = "large timing test: allocates ~700 MB; run manually with --ignored"] +async fn fork_at_extreme_state_under_10ms() { + // 1M entries = ~700 MB RSS. On any modern hardware (Linux physical, + // macOS arm64, modern EC2 HVM) fork should be well under 10 ms. + // + // This is the regression tripwire for the SEV-1 incident class: + // if anyone re-introduces an O(N) operation under state_tables.lock(), + // this test detects it at scale. + let app_state = build_app_state(1_000_000); + + // Warm-up (first fork has cold-cache overhead). + let _ = measure_fork(&app_state); + + // Median of 5 samples — fork is noisy and we want a stable read. + let mut samples: Vec = (0..5) + .map(|_| measure_fork(&app_state).as_secs_f64() * 1000.0) + .collect(); + samples.sort_by(|a, b| a.partial_cmp(b).unwrap()); + let median = samples[samples.len() / 2]; + let max = *samples.last().unwrap(); + + println!(); + println!("=== fork() lock-hold at 1M entries (extreme, default test) ==="); + println!(" median: {median:.2}ms"); + println!(" max: {max:.2}ms"); + println!(" samples: {samples:?}"); + + // Hard ceiling: 10 ms. Production-relevant guarantee. + // + // Empirical (Apple M4 release): median ~0.7 ms. + // Empirical (debug build): median ~5-8 ms (allocator/syscall debug + // overhead, not the fix's fault — production runs release). + // + // CI margin: 10 ms ceiling absorbs Linux-runner variance + debug-mode + // overhead while still proving the <10 ms guarantee under the user's + // documented target. + assert!( + median < 10.0, + "fork lock-hold at 1M entries must be <10ms — got median {median:.2}ms (max {max:.2}ms, samples {samples:?})" + ); +} diff --git a/crates/beava-server/tests/snapshot_fork_macos_stress.rs b/crates/beava-server/tests/snapshot_fork_macos_stress.rs new file mode 100644 index 00000000..d7cde9eb --- /dev/null +++ b/crates/beava-server/tests/snapshot_fork_macos_stress.rs @@ -0,0 +1,337 @@ +//! macOS-specific stress test for the fork()+COW snapshot path. +//! +//! Why this exists: macOS does not install `pthread_atfork` handlers for +//! libdispatch / GCD, and Apple explicitly does not support fork-without- +//! exec when any framework code is loaded. The current child path uses +//! only pure-Rust std (`std::fs`, `bincode`) and `libc::_exit`, +//! deliberately avoiding any surface that could touch GCD. This file +//! guards against the regressions that would invalidate that contract: +//! +//! 1. A future dependency pulling in a libdispatch-using API along the +//! child path (Foundation / CoreFoundation / NSURL / mach ports). +//! 2. A future code change calling something that hits libdispatch +//! indirectly through a transitive macOS framework. +//! 3. Cumulative state corruption across many repeated forks (e.g. a +//! malloc-arena leak or a parking_lot lock that subtly desyncs). +//! +//! Failure mode on macOS: the classic libdispatch corruption symptom is +//! a child that hangs forever in `_dispatch_root_queue_push` (or similar). +//! `do_snapshot_via_fork` has an internal kill/reap timeout, and every +//! assertion below is also bounded with `tokio::time::timeout` so a hang +//! becomes a loud, attributable test failure instead of a CI timeout-kill +//! 10 minutes later. + +#![cfg(target_os = "macos")] + +use beava_core::agg_descriptor::{AggregationDescriptor, NamedAggOp}; +use beava_core::agg_op::{AggKind, AggOp, AggOpDescriptor, FIELD_IDX_NONE}; +use beava_core::agg_state::CountState; +use beava_core::agg_state_table::{ensure_capacity_for, AggStateTable, EntityKey}; +use beava_core::op_node::{AggSpec, OpNode}; +use beava_core::registry::Registry; +use beava_core::registry::{DerivationDescriptor, EventDescriptor, OutputKind}; +use beava_core::registry_diff::PayloadNode; +use beava_core::row::Value; +use beava_core::schema::{DerivedSchema, EventSchema, FieldType}; +use beava_core::snapshot_body::SnapshotBody; +use beava_persistence::SnapshotReader; +use beava_server::registry_debug::DevAggState; +use beava_server::snapshot_fork::{do_snapshot_via_fork_with_wait_timeout, ChildExit}; +use beava_server::AppState; +use compact_str::CompactString; +use smallvec::smallvec; +use std::collections::BTreeMap; +use std::process::Command; +use std::sync::atomic::{AtomicBool, Ordering}; +use std::sync::Arc; +use std::time::{Duration, Instant}; +use tempfile::TempDir; + +/// Per-iteration wall-clock cap. A child that touches GCD on macOS +/// typically hangs immediately; 30 s is well past the legitimate fork +/// snapshot cost for `n_entities=500` (sub-second on Apple-M4). +const PER_ITER_TIMEOUT_SECS: u64 = 30; +const CHILD_WAIT_TIMEOUT_SECS: u64 = PER_ITER_TIMEOUT_SECS - 5; +const CHILD_PROCESS_TIMEOUT_SECS: u64 = 180; + +fn count_desc() -> AggOpDescriptor { + AggOpDescriptor { + kind: AggKind::Count, + field: None, + window_ms: None, + where_expr: None, + n: None, + half_life_ms: None, + sub_window_ms: None, + sigma: None, + sketch_params: None, + ext: Default::default(), + field_idx: FIELD_IDX_NONE, + field_idx_into_event_extracted: Vec::new(), + } +} + +fn install_test_aggregation(registry: &Arc) { + let mut event_fields = BTreeMap::new(); + event_fields.insert("user_id".to_string(), FieldType::Str); + let event = EventDescriptor { + name: "Txn".to_string(), + schema: EventSchema { + fields: event_fields, + optional_fields: vec![], + }, + dedupe_key: None, + dedupe_window_ms: None, + keep_events_for_ms: None, + cold_after_ms: None, + registered_at_version: 0, + name_arc: Arc::from(""), + apply_field_names: vec![], + }; + + let mut group_by = BTreeMap::new(); + group_by.insert( + "cnt".to_string(), + AggSpec { + op: "count".to_string(), + params: serde_json::Value::Object(Default::default()), + }, + ); + let mut derived_fields = BTreeMap::new(); + derived_fields.insert("user_id".to_string(), FieldType::Str); + derived_fields.insert("cnt".to_string(), FieldType::I64); + let deriv = DerivationDescriptor { + name: "UserCounts".to_string(), + output_kind: OutputKind::Table, + upstreams: vec!["Txn".to_string()], + ops: vec![OpNode::GroupBy { + keys: vec!["user_id".to_string()], + agg: group_by, + }], + schema: DerivedSchema { + fields: derived_fields, + optional_fields: vec![], + }, + table_primary_key: Some(vec!["user_id".to_string()]), + registered_at_version: 0, + }; + let agg = AggregationDescriptor { + node_name: "UserCounts".to_string(), + source_node_name: "Txn".to_string(), + group_keys: vec!["user_id".to_string()], + features: vec![NamedAggOp { + feature_name: "cnt".to_string(), + descriptor: count_desc(), + }], + agg_id: 0, + field_names: vec![], + cluster_id: 0, + }; + + registry.apply_registration( + vec![PayloadNode::Event(event), PayloadNode::Derivation(deriv)], + vec![], + vec![], + vec![("UserCounts".to_string(), Arc::new(agg))], + ); +} + +fn run_child_test_with_timeout(test_name: &str) { + let mut child = Command::new(std::env::current_exe().expect("current test binary")) + .arg("--exact") + .arg(test_name) + .arg("--ignored") + .arg("--nocapture") + .spawn() + .unwrap_or_else(|e| panic!("spawn child test {test_name}: {e}")); + let deadline = Instant::now() + Duration::from_secs(CHILD_PROCESS_TIMEOUT_SECS); + + loop { + match child + .try_wait() + .unwrap_or_else(|e| panic!("poll child test {test_name}: {e}")) + { + Some(status) if status.success() => return, + Some(status) => panic!("child test {test_name} failed with status {status}"), + None => {} + } + + if Instant::now() >= deadline { + let _ = child.kill(); + let _ = child.wait(); + panic!("child test {test_name} hung > {CHILD_PROCESS_TIMEOUT_SECS}s; killed process"); + } + std::thread::sleep(Duration::from_millis(100)); + } +} + +fn build_app_state(n_entities: usize) -> AppState { + let registry = Arc::new(Registry::new()); + install_test_aggregation(®istry); + let dev_agg = DevAggState::new(registry); + { + let mut tables = dev_agg.state_tables.lock(); + ensure_capacity_for(&mut tables, 1); + let mut table = AggStateTable::new(); + for ent in 0..n_entities { + let key_str = format!("user_{ent:09}"); + let entity_key = EntityKey(smallvec![( + CompactString::from("user_id"), + Value::Str(CompactString::from(key_str.as_str())), + )]); + table.insert_from_entity_key( + entity_key, + vec![AggOp::Count(CountState { n: ent as u64 })], + ); + } + tables[0] = table; + } + let (wal_sink, _wal_join) = beava_persistence::WalSink::spawn_no_op(); + let idem_cache = Arc::new(beava_server::idem_cache::IdemCache::new()); + AppState::new(dev_agg, wal_sink, idem_cache) +} + +/// 20 fork-snapshots back-to-back, each bounded by `PER_ITER_TIMEOUT_SECS`. +/// If any iteration hangs (classic libdispatch symptom in the child), the +/// timeout fires with an attributable panic instead of CI hanging. +#[test] +fn fork_snapshot_repeated_macos_does_not_hang() { + run_child_test_with_timeout("fork_snapshot_repeated_macos_child"); +} + +#[tokio::test(flavor = "current_thread")] +#[ignore = "run by fork_snapshot_repeated_macos_does_not_hang process-level timeout harness"] +async fn fork_snapshot_repeated_macos_child() { + let tmp = TempDir::new().unwrap(); + let app_state = build_app_state(500); + + for i in 0..20u64 { + let snapshot_lsn = i + 1; + let exit = match tokio::time::timeout( + Duration::from_secs(PER_ITER_TIMEOUT_SECS), + do_snapshot_via_fork_with_wait_timeout( + tmp.path(), + snapshot_lsn, + &app_state, + Duration::from_secs(CHILD_WAIT_TIMEOUT_SECS), + ), + ) + .await + { + Ok(res) => { + res.unwrap_or_else(|e| panic!("iter {i}: fork-snapshot returned error: {e}")) + } + Err(_) => panic!( + "iter {i}: fork-snapshot hung > {PER_ITER_TIMEOUT_SECS}s — \ + possible libdispatch / GCD corruption in child path" + ), + }; + + match exit { + ChildExit::Success { .. } => {} + ChildExit::Failure { code, message } => { + panic!("iter {i}: child failed code={code} message={message}"); + } + } + + let path = tmp.path().join(format!("snapshot-{snapshot_lsn:016x}.bvs")); + assert!(path.exists(), "iter {i}: snapshot file missing at {path:?}"); + let (header, body) = SnapshotReader::open(&path) + .unwrap_or_else(|e| panic!("iter {i}: snapshot must decode: {e}")); + assert_eq!(header.snapshot_lsn, snapshot_lsn); + let decoded = SnapshotBody::decode(&body) + .unwrap_or_else(|e| panic!("iter {i}: body must decode: {e}")); + assert_eq!( + decoded + .state_tables + .get("UserCounts") + .map(|entries| entries.len()), + Some(500), + "iter {i}: snapshot must serialize the registered aggregation state" + ); + + // Parent must still be able to acquire the state_tables lock. + // If the fork path leaked a held lock back into the parent, this + // would deadlock and the next iteration's timeout would catch it. + let _guard = app_state.dev_agg.state_tables.lock(); + } +} + +/// 10 fork-snapshots while a sibling thread continuously grabs the +/// `state_tables` lock to mutate state. Validates that lock contention +/// + concurrent allocation in the parent doesn't poison the child path +/// (e.g. a malloc arena left mid-mutation at fork time). +#[test] +fn fork_snapshot_under_concurrent_mutation_macos_stable() { + run_child_test_with_timeout("fork_snapshot_under_concurrent_mutation_macos_child"); +} + +#[tokio::test(flavor = "current_thread")] +#[ignore = "run by fork_snapshot_under_concurrent_mutation_macos_stable process-level timeout harness"] +async fn fork_snapshot_under_concurrent_mutation_macos_child() { + let tmp = TempDir::new().unwrap(); + let app_state = Arc::new(build_app_state(500)); + let stop = Arc::new(AtomicBool::new(false)); + + let writer_state = Arc::clone(&app_state); + let writer_stop = Arc::clone(&stop); + let writer = std::thread::spawn(move || { + let mut bump: u64 = 0; + while !writer_stop.load(Ordering::Relaxed) { + { + let mut tables = writer_state.dev_agg.state_tables.lock(); + if let Some(table) = tables.get_mut(0) { + let key_str = format!("mut_{:03}", bump % 64); + let entity_key = EntityKey(smallvec![( + CompactString::from("user_id"), + Value::Str(CompactString::from(key_str.as_str())), + )]); + table.insert_from_entity_key( + entity_key, + vec![AggOp::Count(CountState { n: bump })], + ); + if let Some(ops) = table.single_str.values_mut().next() { + if let Some(AggOp::Count(count)) = ops.get_mut(0) { + count.n = count.n.wrapping_add(1); + } + } + } + } + bump = bump.wrapping_add(1); + if bump % 256 == 0 { + std::thread::yield_now(); + } + } + }); + + for i in 0..10u64 { + let snapshot_lsn = 100 + i; + let exit = match tokio::time::timeout( + Duration::from_secs(PER_ITER_TIMEOUT_SECS), + do_snapshot_via_fork_with_wait_timeout( + tmp.path(), + snapshot_lsn, + &app_state, + Duration::from_secs(CHILD_WAIT_TIMEOUT_SECS), + ), + ) + .await + { + Ok(res) => res.unwrap_or_else(|e| panic!("iter {i}: fork-snapshot error: {e}")), + Err(_) => { + stop.store(true, Ordering::Relaxed); + panic!( + "iter {i}: fork-snapshot hung > {PER_ITER_TIMEOUT_SECS}s \ + under concurrent parent mutation" + ); + } + }; + assert!( + matches!(exit, ChildExit::Success { .. }), + "iter {i}: {exit:?}" + ); + } + + stop.store(true, Ordering::Relaxed); + writer.join().expect("writer thread join"); +} diff --git a/crates/beava-server/tests/snapshot_fork_scaling.rs b/crates/beava-server/tests/snapshot_fork_scaling.rs new file mode 100644 index 00000000..a5dbf9aa --- /dev/null +++ b/crates/beava-server/tests/snapshot_fork_scaling.rs @@ -0,0 +1,288 @@ +//! Empirical chart of fork() syscall cost vs beava process VM size. +//! +//! ## Headline finding +//! +//! On Apple M4 release-mode tests, fork()'s lock-hold has TWO regimes: +//! +//! **Fresh process (after boot, before VM grew):** +//! Linear in current RSS. ~1ms per GB. 1M entries → 0.7ms, 10M → 12ms. +//! +//! **Long-lived process (after big allocations + frees):** +//! Linear in *virtual* memory size — which on macOS+libmalloc and +//! Linux+glibc *does not shrink back* after frees in the usual case. +//! 14-18ms even after state shrinks, because the page table the allocator +//! has touched stays mapped. +//! +//! Production implication: a beava process running for days/weeks will +//! see fork latency closer to the long-lived numbers (10-20ms) than to +//! the fresh-process numbers (sub-millisecond). +//! +//! ## Is 10ms too long? +//! +//! For the kalshi-pulse incident (#151): no — going from 2.3 s lock-hold +//! to 15 ms is a 150× improvement. /ping never trips a 3 s healthcheck; +//! incident closed. +//! +//! For beava's 3M EPS/core target: borderline. A 15ms fork queues ~45k +//! events on the apply thread once per 60 s snapshot cycle = 0.025% +//! wall-clock blocked. Tolerable for fraud-serving workloads but visible +//! as a latency spike at snapshot time. +//! +//! ## Run +//! +//! ```sh +//! cargo test --release -p beava-server --test snapshot_fork_scaling \ +//! -- --ignored --nocapture --test-threads=1 +//! ``` + +use beava_core::agg_op::AggOp; +use beava_core::agg_state::CountState; +use beava_core::agg_state_table::{AggStateTable, EntityKey}; +use beava_core::registry::Registry; +use beava_core::row::Value; +use beava_server::registry_debug::DevAggState; +use beava_server::AppState; +use compact_str::CompactString; +use smallvec::smallvec; +use std::sync::Arc; +use std::time::{Duration, Instant}; + +fn build_app_state(n_entities: usize) -> AppState { + let registry = Arc::new(Registry::new()); + let dev_agg = DevAggState::new(registry); + { + let mut tables = dev_agg.state_tables.lock(); + let mut table = AggStateTable::new(); + for ent in 0..n_entities { + let key_str = format!("user_{ent:09}"); + let entity_key = EntityKey(smallvec![( + CompactString::from("user_id"), + Value::Str(CompactString::from(key_str.as_str())), + )]); + table.insert_from_entity_key( + entity_key, + vec![AggOp::Count(CountState { n: ent as u64 })], + ); + } + tables.push(table); + } + let (wal_sink, _wal_join) = beava_persistence::WalSink::spawn_no_op(); + let idem_cache = Arc::new(beava_server::idem_cache::IdemCache::new()); + AppState::new(dev_agg, wal_sink, idem_cache) +} + +#[cfg(unix)] +fn measure_fork(app_state: &AppState) -> Duration { + let lock_start = Instant::now(); + let state_lock = app_state.dev_agg.state_tables.lock(); + let pid = unsafe { libc::fork() }; + let lock_held = lock_start.elapsed(); + if pid == 0 { + unsafe { libc::_exit(0) }; + } + assert!(pid > 0, "fork failed: {}", std::io::Error::last_os_error()); + drop(state_lock); + let mut status: libc::c_int = 0; + unsafe { + libc::waitpid(pid, &mut status, 0); + } + lock_held +} + +/// Read RSS in bytes (current resident set size of this process). +#[cfg(target_os = "macos")] +fn process_rss_bytes() -> Option { + unsafe { + let mut info: libc::mach_task_basic_info = std::mem::zeroed(); + let mut count = (std::mem::size_of::() / 4) as u32; + #[allow(deprecated)] // libc still re-exports it; mach2 not in deps + let task = libc::mach_task_self(); + let ret = libc::task_info( + task, + libc::MACH_TASK_BASIC_INFO, + &mut info as *mut _ as *mut i32, + &mut count, + ); + if ret == 0 { + Some(info.resident_size) + } else { + None + } + } +} + +#[cfg(target_os = "linux")] +fn process_rss_bytes() -> Option { + let statm = std::fs::read_to_string("/proc/self/statm").ok()?; + let rss_pages: u64 = statm.split_whitespace().nth(1)?.parse().ok()?; + let page_size = unsafe { libc::sysconf(libc::_SC_PAGESIZE) } as u64; + Some(rss_pages * page_size) +} + +#[cfg(not(any(target_os = "macos", target_os = "linux")))] +fn process_rss_bytes() -> Option { + None +} + +/// Sweep fork() syscall latency from 1M to 20M entries; print the curve +/// and the current process RSS at each scale. Informational — no +/// hard assertion, because the answer depends on OS allocator state. +#[cfg(unix)] +#[tokio::test(flavor = "current_thread")] +#[ignore = "scaling sweep: builds up to ~6GB; run with --ignored --release"] +async fn fork_syscall_vs_process_rss() { + println!(); + println!("=== fork() syscall latency vs beava process RSS ==="); + println!( + "{:>10} {:>12} {:>14} {:>14}", + "entries", "rss_MB", "fork_ms_median", "fork_ms_max" + ); + println!("{}", "-".repeat(56)); + + let sizes = [1_000_000usize, 2_500_000, 5_000_000, 10_000_000, 20_000_000]; + + for &n in &sizes { + let app_state = build_app_state(n); + let rss_mb = process_rss_bytes().map(|b| b as f64 / (1024.0 * 1024.0)); + + let _ = measure_fork(&app_state); // warm-up + let mut samples: Vec = (0..5) + .map(|_| measure_fork(&app_state).as_secs_f64() * 1000.0) + .collect(); + samples.sort_by(|a, b| a.partial_cmp(b).unwrap()); + let median = samples[samples.len() / 2]; + let max = *samples.last().unwrap(); + + let rss_str = rss_mb + .map(|m| format!("{:.0}", m)) + .unwrap_or_else(|| "?".to_string()); + println!( + "{:>10} {:>9} MB {:>11.2}ms {:>11.2}ms", + n, rss_str, median, max + ); + + drop(app_state); + } + + println!(); + println!("Caveat: RSS shrinks when state is dropped, but the process's"); + println!("virtual address space (the thing fork() copies page tables for)"); + println!("often does NOT shrink back. Long-lived production processes will"); + println!("see fork closer to the WORST-CASE row in this chart even when"); + println!("current state is small."); +} + +/// The user-relevant upper bound at the incident's apparent scale (~5M +/// entries). On a long-running process this is the realistic ceiling: +/// 50ms. Empirically Apple M4 release: 4-15ms depending on prior VM +/// growth. We assert 50ms (3× safety margin over observed worst case). +#[cfg(unix)] +#[tokio::test(flavor = "current_thread")] +#[ignore = "big-state: builds ~2GB; run with --ignored --release"] +async fn fork_lock_hold_at_5m_entries_under_50ms() { + let app_state = build_app_state(5_000_000); + let _ = measure_fork(&app_state); + let mut samples: Vec = (0..5) + .map(|_| measure_fork(&app_state).as_secs_f64() * 1000.0) + .collect(); + samples.sort_by(|a, b| a.partial_cmp(b).unwrap()); + let median = samples[samples.len() / 2]; + let max = *samples.last().unwrap(); + println!(); + println!("fork lock-hold @ N=5M: median {median:.2}ms max {max:.2}ms"); + println!(" Apple M4 fresh-process: ~4ms; long-lived process: ~14ms."); + // Production-realistic ceiling: 50ms. Anything under this means the + // kalshi-pulse SEV-1 (#151) is resolved; no docker healthcheck is + // going to trip on a 50ms /ping spike once per 60s. + assert!( + median < 50.0, + "fork at 5M entries must be <50ms — got median {median:.2}ms (max {max:.2}ms)" + ); +} + +/// Larger scale — 10M entries (≈3-4 GB RSS, beyond typical fraud workloads +/// but not unreasonable for behavioral analytics). Production-realistic +/// ceiling here: 100ms. +#[cfg(unix)] +#[tokio::test(flavor = "current_thread")] +#[ignore = "big-state: builds ~3-4GB; run with --ignored --release"] +async fn fork_lock_hold_at_10m_entries_under_100ms() { + let app_state = build_app_state(10_000_000); + let _ = measure_fork(&app_state); + let mut samples: Vec = (0..5) + .map(|_| measure_fork(&app_state).as_secs_f64() * 1000.0) + .collect(); + samples.sort_by(|a, b| a.partial_cmp(b).unwrap()); + let median = samples[samples.len() / 2]; + let max = *samples.last().unwrap(); + println!(); + println!("fork lock-hold @ N=10M: median {median:.2}ms max {max:.2}ms"); + println!(" Apple M4 fresh-process: ~12ms; long-lived process: ~14ms."); + // 100ms ceiling. At this scale you should be considering whether + // fork is still the right answer — at 20M+ you'd want ArcSwap or + // a shard-the-state approach. + assert!( + median < 100.0, + "fork at 10M entries must be <100ms — got median {median:.2}ms (max {max:.2}ms)" + ); +} + +/// Stress: 20M entries (~6 GB RSS). This is well beyond what beava +/// recommends per-instance (the 7 KB/entity budget says 100M-entity boxes +/// should be sharded across multiple beava instances). Tests the fork +/// ceiling at near-worst-case single-instance scale. +#[cfg(unix)] +#[tokio::test(flavor = "current_thread")] +#[ignore = "stress: builds ~6GB; run with --ignored --release"] +async fn fork_lock_hold_at_20m_entries_under_200ms() { + let app_state = build_app_state(20_000_000); + let _ = measure_fork(&app_state); + let mut samples: Vec = (0..5) + .map(|_| measure_fork(&app_state).as_secs_f64() * 1000.0) + .collect(); + samples.sort_by(|a, b| a.partial_cmp(b).unwrap()); + let median = samples[samples.len() / 2]; + let max = *samples.last().unwrap(); + println!(); + println!("fork lock-hold @ N=20M: median {median:.2}ms max {max:.2}ms"); + println!(" Apple M4: ~18-20ms. Past 20M consider ArcSwap."); + assert!( + median < 200.0, + "fork at 20M entries must be <200ms — got median {median:.2}ms (max {max:.2}ms)" + ); +} + +/// Best-case floor: small state in a fresh process. This is what +/// production beava sees at boot, before any state has accumulated. Any +/// regression below this baseline (e.g. an extra page-touching allocation +/// somewhere in app_state) would show up here. +/// +/// MUST be invoked as the FIRST test in this binary, e.g. by running just +/// this test on its own: +/// +/// cargo test --release -p beava-server --test snapshot_fork_scaling \ +/// fork_at_1m_fresh_process_under_5ms -- --ignored --nocapture +/// +/// Running with the full --test-threads=1 sweep makes this test fail +/// because earlier tests bloat the process VM. +#[cfg(unix)] +#[tokio::test(flavor = "current_thread")] +#[ignore = "fresh-process baseline: must run alone — bare cargo test cmd above"] +async fn fork_at_1m_fresh_process_under_5ms() { + let app_state = build_app_state(1_000_000); + let _ = measure_fork(&app_state); + let mut samples: Vec = (0..5) + .map(|_| measure_fork(&app_state).as_secs_f64() * 1000.0) + .collect(); + samples.sort_by(|a, b| a.partial_cmp(b).unwrap()); + let median = samples[samples.len() / 2]; + println!(); + println!("fork @ N=1M (fresh process): median {median:.2}ms"); + println!(" Best-case floor. Long-running process: see other tests."); + // 1M entries in a never-touched-larger-VM process: <5ms. Apple M4 + // empirical: ~0.7ms. + assert!( + median < 5.0, + "fork at 1M entries on fresh process should be <5ms — got {median:.2}ms (was this test run alone? see comment)" + ); +} diff --git a/crates/beava-server/tests/snapshot_lock_contention.rs b/crates/beava-server/tests/snapshot_lock_contention.rs new file mode 100644 index 00000000..c6d23e45 --- /dev/null +++ b/crates/beava-server/tests/snapshot_lock_contention.rs @@ -0,0 +1,300 @@ +//! Lock-hold comparison: legacy in-process snapshot vs fork() snapshot. +//! +//! The legacy path holds `state_tables.lock()` for the entire duration of +//! `SnapshotBody::from_live` (which deep-clones every entry). The fork path +//! holds it only across the `fork()` syscall (~µs). +//! +//! These tests measure the lock-hold duration **directly inline** rather +//! than racing a side-thread sampler, so they're CI-stable. + +use beava_core::agg_op::AggOp; +use beava_core::agg_state::CountState; +use beava_core::agg_state_table::{AggStateTable, EntityKey}; +use beava_core::registry::Registry; +use beava_core::row::Value; +use beava_core::snapshot_body::SnapshotBody; +use beava_persistence::SnapshotWriter; +use beava_server::registry_debug::DevAggState; +use beava_server::snapshot_fork::do_snapshot_via_fork; +use beava_server::AppState; +use compact_str::CompactString; +use smallvec::smallvec; +use std::path::Path; +use std::sync::atomic::Ordering; +use std::sync::Arc; +use std::time::{Duration, Instant}; +use tempfile::TempDir; + +#[allow(dead_code)] // SnapshotBody used only in the full-snapshot helper +fn _import_anchor() { + let _: Option<&SnapshotBody> = None; +} + +fn build_app_state(n_entities: usize) -> AppState { + let registry = Arc::new(Registry::new()); + let dev_agg = DevAggState::new(registry); + { + let mut tables = dev_agg.state_tables.lock(); + let mut table = AggStateTable::new(); + for ent in 0..n_entities { + let key_str = format!("user_{ent:09}"); + let entity_key = EntityKey(smallvec![( + CompactString::from("user_id"), + Value::Str(CompactString::from(key_str.as_str())), + )]); + table.insert_from_entity_key( + entity_key, + vec![AggOp::Count(CountState { n: ent as u64 })], + ); + } + tables.push(table); + } + let (wal_sink, _wal_join) = beava_persistence::WalSink::spawn_no_op(); + let idem_cache = Arc::new(beava_server::idem_cache::IdemCache::new()); + AppState::new(dev_agg, wal_sink, idem_cache) +} + +/// Measure the legacy lock-hold scope **directly**. +/// +/// Mirrors the inner loop of `SnapshotBody::from_live` byte-for-byte +/// (`table.iter_sorted().map(clone, clone).collect()`) — that's the +/// operation under `state_tables.lock()` in the legacy path. +/// +/// We bypass `SnapshotBody::from_live` here because that function iterates +/// `Registry::compiled_aggregations`, which is empty in this test +/// harness (we populate StateTables directly to avoid the register- +/// validate path's complexity). The clone-collect we time below is +/// what `from_live` would do once for each registered aggregation. +fn measure_legacy_lock_hold(app_state: &AppState) -> Duration { + let lock_start = Instant::now(); + let _entries: Vec<(EntityKey, Vec)> = { + let tables = app_state.dev_agg.state_tables.lock(); + tables[0] + .iter_sorted() + .map(|(k, v)| (k.clone(), v.clone())) + .collect() + }; + lock_start.elapsed() +} + +/// End-to-end legacy snapshot (used to confirm the full path still works +/// — not used for lock-hold timing). Returns total wall time. +#[allow(dead_code)] +fn run_legacy_snapshot_full(app_state: &AppState, dir: &Path, lsn: u64) -> Duration { + let next_event_id = app_state.dev_agg.next_event_id.load(Ordering::Relaxed); + let query_time_ms = app_state.dev_agg.query_time_ms.load(Ordering::Relaxed) as i64; + let t0 = Instant::now(); + let body = { + let registry_snap = app_state.dev_agg.registry.snapshot(); + let tables = app_state.dev_agg.state_tables.lock(); + SnapshotBody::from_live(®istry_snap, &tables, next_event_id, query_time_ms) + }; + let encoded = body.encode().expect("encode"); + SnapshotWriter::write(dir, lsn, body.registry.version, &encoded).expect("write"); + t0.elapsed() +} + +/// Direct measurement of the fork path's lock-hold scope — the parent +/// only holds the lock across the `libc::fork()` syscall. +#[cfg(unix)] +fn measure_fork_parent_lock_hold(app_state: &AppState) -> Duration { + // Mirrors snapshot_fork::do_snapshot_via_fork lock scope verbatim. + // We can't reuse the public function because it does the whole + // snapshot. This measures ONLY the parent-side lock scope. + let lock_start = Instant::now(); + let state_lock = app_state.dev_agg.state_tables.lock(); + let pid = unsafe { libc::fork() }; + let lock_held = lock_start.elapsed(); + + if pid == 0 { + // Child: exit immediately. Snapshot itself is tested elsewhere. + unsafe { libc::_exit(0) }; + } + assert!(pid > 0, "fork failed: {}", std::io::Error::last_os_error()); + + drop(state_lock); + + // Reap so we don't leak a zombie. + let mut status: libc::c_int = 0; + unsafe { + libc::waitpid(pid, &mut status, 0); + } + + lock_held +} + +#[cfg(unix)] +#[tokio::test(flavor = "current_thread")] +async fn legacy_lock_hold_scales_with_state_size() { + println!(); + println!("=== Legacy in-process snapshot: lock-hold scales with N ==="); + println!("{:>10} {:>14}", "entries", "lock_held_ms"); + println!("{}", "-".repeat(28)); + + let mut prev_lock_ms = 0.0; + for &n in &[1_000usize, 50_000, 200_000] { + let app_state = build_app_state(n); + let _ = measure_legacy_lock_hold(&app_state); // warm-up + let mut samples: Vec = (0..3) + .map(|_| measure_legacy_lock_hold(&app_state).as_secs_f64() * 1000.0) + .collect(); + samples.sort_by(|a, b| a.partial_cmp(b).unwrap()); + let lock_ms = samples[1]; + + println!("{:>10} {:>11.2}ms", n, lock_ms); + + // Each step up in N must increase lock_held — proves the legacy + // path is O(N) in state size. + if n > 1_000 { + assert!( + lock_ms > prev_lock_ms, + "legacy lock_held must scale with N — N={n} got {lock_ms:.2}ms, prev {prev_lock_ms:.2}ms" + ); + } + prev_lock_ms = lock_ms; + } + + // At 200k entries the lock-held duration must be visibly non-trivial. + // Loose floor (1ms) to avoid CI flake while still proving blocking + // behavior exists. + assert!( + prev_lock_ms >= 1.0, + "legacy lock-hold at 200k entries should be >=1ms — got {prev_lock_ms:.2}ms" + ); +} + +#[cfg(unix)] +#[tokio::test(flavor = "current_thread")] +async fn fork_lock_hold_is_microseconds_regardless_of_state_size() { + println!(); + println!("=== fork() snapshot: lock-hold is O(1) (fork syscall only) ==="); + println!("{:>10} {:>14}", "entries", "lock_held_ms"); + println!("{}", "-".repeat(28)); + + for &n in &[1_000usize, 50_000, 200_000] { + let app_state = build_app_state(n); + + // Warm-up. + let _ = measure_fork_parent_lock_hold(&app_state); + + // Median of 3. + let mut samples = Vec::with_capacity(3); + for _ in 0..3 { + samples.push(measure_fork_parent_lock_hold(&app_state).as_secs_f64() * 1000.0); + } + samples.sort_by(|a, b| a.partial_cmp(b).unwrap()); + let lock_ms = samples[1]; + + println!("{:>10} {:>11.2}ms", n, lock_ms); + + // Generous CI margin: fork syscall + lock release should be well + // under 50ms even on slow runners. Production sub-millisecond on + // Apple M4 + low-single-digit ms on Linux CI. + assert!( + lock_ms < 50.0, + "fork lock-hold must be O(1) — N={n} got {lock_ms:.2}ms" + ); + } +} + +#[cfg(unix)] +#[tokio::test(flavor = "current_thread")] +async fn fork_vs_legacy_lock_hold_at_same_state_size() { + // Side-by-side comparison at a fixed state size. Fork should be + // dramatically shorter (orders of magnitude). + let app_state = build_app_state(100_000); + + // Warm-up both. + let _ = measure_legacy_lock_hold(&app_state); + let _ = measure_fork_parent_lock_hold(&app_state); + + // Median of 3 for both. + let mut legacy_samples: Vec = (0..3) + .map(|_| measure_legacy_lock_hold(&app_state).as_secs_f64() * 1000.0) + .collect(); + let mut fork_samples: Vec = (0..3) + .map(|_| measure_fork_parent_lock_hold(&app_state).as_secs_f64() * 1000.0) + .collect(); + legacy_samples.sort_by(|a, b| a.partial_cmp(b).unwrap()); + fork_samples.sort_by(|a, b| a.partial_cmp(b).unwrap()); + let legacy_ms = legacy_samples[1]; + let fork_ms = fork_samples[1]; + let speedup = legacy_ms / fork_ms.max(0.001); + + println!(); + println!("=== Lock-hold comparison @ N=100k entities ==="); + println!(" legacy: {legacy_ms:>7.2}ms (median of 3)"); + println!(" fork: {fork_ms:>7.2}ms (median of 3)"); + println!(" speedup: {speedup:>5.1}×"); + println!(); + + // The point of the fix: fork must be at least 5× faster than legacy + // at this scale. (Empirically Apple M4: legacy ~30ms, fork ~0.3ms, + // speedup ~100×. CI floor 5× covers worst-case Linux runner variance.) + assert!( + speedup >= 5.0, + "fork must be >=5× faster than legacy at N=100k — got {speedup:.1}× (legacy={legacy_ms:.2}ms fork={fork_ms:.2}ms)" + ); +} + +/// End-to-end: full `do_snapshot_via_fork` (including the child's encode + +/// write + waitpid) must still leave the parent's apply lock available +/// quickly. This is the integration-level guarantee. +#[cfg(unix)] +#[tokio::test(flavor = "current_thread")] +async fn fork_full_path_apply_lock_available_during_child_work() { + let tmp = TempDir::new().unwrap(); + let app_state = build_app_state(100_000); + + let app_for_probe = app_state.clone(); + let probe = std::thread::spawn(move || { + // Try to grab the lock in a tight loop after a brief warm-up. + // After fork() returns in the parent, the lock should be available + // immediately even though the child is still serializing. + std::thread::sleep(Duration::from_millis(2)); + let mut acquired_ms = None; + let t0 = Instant::now(); + loop { + if let Some(_g) = app_for_probe.dev_agg.state_tables.try_lock() { + acquired_ms = Some(t0.elapsed()); + break; + } + if t0.elapsed() > Duration::from_secs(5) { + break; + } + std::thread::sleep(Duration::from_micros(50)); + } + acquired_ms + }); + + let t_parent = Instant::now(); + let _ = do_snapshot_via_fork(tmp.path(), 1, &app_state) + .await + .expect("fork-snapshot"); + let parent_total = t_parent.elapsed(); + let acquired_ms = probe.join().unwrap(); + + println!(); + println!("=== Full fork path: parent apply-lock availability ==="); + println!( + " parent total (incl. waitpid): {:.2}ms", + parent_total.as_secs_f64() * 1000.0 + ); + if let Some(d) = acquired_ms { + println!( + " probe acquired lock at: +{:.2}ms after probe start", + d.as_secs_f64() * 1000.0 + ); + } else { + println!(" probe never acquired lock within 5s"); + } + + let acquired = acquired_ms.expect("probe should acquire the lock"); + // Apply thread should be unblocked within 100ms even at 100k entries. + // This is the user-visible guarantee. + assert!( + acquired < Duration::from_millis(100), + "apply lock must be available within 100ms — got {:?}", + acquired + ); +} diff --git a/crates/beava-server/tests/snapshot_metrics.rs b/crates/beava-server/tests/snapshot_metrics.rs new file mode 100644 index 00000000..4bb216f2 --- /dev/null +++ b/crates/beava-server/tests/snapshot_metrics.rs @@ -0,0 +1,74 @@ +//! Snapshot instrumentation exposed on the admin /metrics endpoint. + +#![cfg(feature = "testing")] + +use beava_server::testing::{TestServer, TestServerBuilder}; + +async fn fetch_metrics(ts: &TestServer) -> String { + reqwest::get(format!("{}/metrics", ts.admin_url())) + .await + .expect("/metrics request") + .text() + .await + .expect("/metrics body") +} + +fn scrape_metric_value<'a>(body: &'a str, name: &str) -> Option<&'a str> { + for line in body.lines() { + let trimmed = line.trim_start(); + if trimmed.starts_with('#') { + continue; + } + if let Some(rest) = trimmed.strip_prefix(name) { + match rest.chars().next() { + Some(' ') | Some('\t') | Some('{') => {} + _ => continue, + } + return trimmed.split_whitespace().last(); + } + } + None +} + +#[tokio::test(flavor = "multi_thread", worker_threads = 4)] +async fn metrics_endpoint_exposes_last_snapshot_stats() { + let ts = TestServerBuilder::new() + .snapshot_interval_ms(60_000) + .spawn() + .await + .expect("spawn"); + + let initial = fetch_metrics(&ts).await; + for help in [ + "# HELP beava_snapshot_last_duration_seconds", + "# HELP beava_snapshot_last_bytes", + "# HELP beava_snapshot_last_fsync_seconds", + ] { + assert!( + initial.contains(help), + "metrics body must contain `{help}`; got:\n{initial}" + ); + } + + ts.force_snapshot_now().await.expect("force snapshot"); + + let after = fetch_metrics(&ts).await; + let bytes = scrape_metric_value(&after, "beava_snapshot_last_bytes") + .expect("snapshot bytes metric") + .parse::() + .expect("snapshot bytes value"); + let duration = scrape_metric_value(&after, "beava_snapshot_last_duration_seconds") + .expect("snapshot duration metric") + .parse::() + .expect("snapshot duration value"); + let fsync = scrape_metric_value(&after, "beava_snapshot_last_fsync_seconds") + .expect("snapshot fsync metric") + .parse::() + .expect("snapshot fsync value"); + + assert!(bytes > 0, "forced snapshot should report bytes > 0"); + assert!(duration.is_finite() && duration >= 0.0); + assert!(fsync.is_finite() && fsync >= 0.0); + + ts.shutdown().await.ok(); +} diff --git a/crates/beava-server/tests/snapshot_recovery_time.rs b/crates/beava-server/tests/snapshot_recovery_time.rs new file mode 100644 index 00000000..7ba46547 --- /dev/null +++ b/crates/beava-server/tests/snapshot_recovery_time.rs @@ -0,0 +1,222 @@ +//! Snapshot recovery time tests. +//! +//! Measure how long it takes to recover a snapshot end-to-end: +//! `SnapshotReader::open` (verify magic + CRC + read body bytes) plus +//! `SnapshotBody::decode` (bincode deserialize). Both are on the boot +//! critical path — a beava process that just restarted cannot serve +//! traffic until recovery completes. +//! +//! The user-visible question this test answers: **if production state is +//! 507 MB encoded (~5-10M entries), how long does a restart's snapshot +//! recovery take?** +//! +//! We also verify round-trip correctness: bytes written by +//! `SnapshotWriter::write` decode byte-identically via `SnapshotReader::open` +//! + `SnapshotBody::decode`. + +use beava_core::agg_op::AggOp; +use beava_core::agg_state::CountState; +use beava_core::agg_state_table::EntityKey; +use beava_core::row::Value; +use beava_core::snapshot_body::{ + RegistryDescriptorsOnly, SerializedStateTables, SnapshotBody, SNAPSHOT_BODY_FORMAT_VERSION, +}; +use beava_persistence::{SnapshotReader, SnapshotWriter}; +use compact_str::CompactString; +use smallvec::smallvec; +use std::collections::BTreeMap; +use std::time::Instant; +use tempfile::TempDir; + +/// Build a `SnapshotBody` populated with one aggregation node ("agg_0") +/// containing N entities × Count entries. +fn build_body(n_entities: usize) -> SnapshotBody { + let mut entries: Vec<(EntityKey, Vec)> = Vec::with_capacity(n_entities); + for ent in 0..n_entities { + let key_str = format!("user_{ent:09}"); + let entity_key = EntityKey(smallvec![( + CompactString::from("user_id"), + Value::Str(CompactString::from(key_str.as_str())), + )]); + entries.push((entity_key, vec![AggOp::Count(CountState { n: ent as u64 })])); + } + let mut state_tables: SerializedStateTables = BTreeMap::new(); + state_tables.insert("agg_0".to_string(), entries); + + SnapshotBody { + body_format_version: SNAPSHOT_BODY_FORMAT_VERSION, + registry: RegistryDescriptorsOnly::default(), + state_tables, + next_event_id: 42, + query_time_ms: 1_700_000_000_000, + } +} + +/// Encode + write a snapshot to disk; return the final file path. +fn write_snapshot(dir: &std::path::Path, lsn: u64, body: &SnapshotBody) -> std::path::PathBuf { + let encoded = body.encode().expect("encode"); + SnapshotWriter::write(dir, lsn, body.registry.version, &encoded).expect("write") +} + +#[test] +fn snapshot_round_trip_byte_identical() { + // Smallest possible round-trip — verifies the contract. + let tmp = TempDir::new().unwrap(); + let body = build_body(100); + + let encoded_in = body.encode().expect("encode"); + let path = write_snapshot(tmp.path(), 1, &body); + + let (header, encoded_out) = SnapshotReader::open(&path).expect("open"); + assert_eq!(header.snapshot_lsn, 1); + assert_eq!(encoded_in, encoded_out, "encoded bytes must round-trip"); + + let decoded = SnapshotBody::decode(&encoded_out).expect("decode"); + assert_eq!(decoded.next_event_id, body.next_event_id); + assert_eq!(decoded.query_time_ms, body.query_time_ms); + assert_eq!(decoded.state_tables.len(), 1); + assert_eq!(decoded.state_tables["agg_0"].len(), 100); +} + +#[test] +fn snapshot_recovery_time_scaling() { + let sizes: &[usize] = &[1_000, 10_000, 100_000]; + + println!(); + println!("=== Snapshot recovery time vs state size ==="); + println!("(SnapshotReader::open + SnapshotBody::decode)"); + println!(); + println!( + "{:>10} {:>14} {:>14} {:>16} {:>18}", + "entries", "encoded_KB", "open_ms", "decode_ms", "MB/s_decode" + ); + println!("{}", "-".repeat(80)); + + let tmp = TempDir::new().unwrap(); + for &n in sizes { + let body = build_body(n); + let path = write_snapshot(tmp.path(), n as u64, &body); + let file_size_kb = std::fs::metadata(&path).unwrap().len() as f64 / 1024.0; + + // Median of 3 to smooth filesystem cache effects. + let mut open_samples = Vec::with_capacity(3); + let mut decode_samples = Vec::with_capacity(3); + let mut last_body_len = 0usize; + for _ in 0..3 { + let t0 = Instant::now(); + let (_h, encoded) = SnapshotReader::open(&path).expect("open"); + let open_elapsed = t0.elapsed(); + + let t1 = Instant::now(); + let decoded = SnapshotBody::decode(&encoded).expect("decode"); + let decode_elapsed = t1.elapsed(); + + open_samples.push(open_elapsed.as_secs_f64() * 1000.0); + decode_samples.push(decode_elapsed.as_secs_f64() * 1000.0); + last_body_len = encoded.len(); + + // Touch the decoded value so the optimizer doesn't elide it. + assert_eq!(decoded.state_tables["agg_0"].len(), n); + } + open_samples.sort_by(|a, b| a.partial_cmp(b).unwrap()); + decode_samples.sort_by(|a, b| a.partial_cmp(b).unwrap()); + let open_ms = open_samples[1]; + let decode_ms = decode_samples[1]; + let mb_per_s = (last_body_len as f64 / (1024.0 * 1024.0)) / (decode_ms / 1000.0); + + println!( + "{:>10} {:>11.1} KB {:>11.2}ms {:>13.2}ms {:>15.1}", + n, file_size_kb, open_ms, decode_ms, mb_per_s + ); + } + + println!(); + println!("Projection to incident scale (507 MB encoded snapshot):"); + println!("- decode throughput at large N is ~constant (MB/s above)"); + println!("- recovery wall-clock = open + decode + install (install adds"); + println!(" per-entity HashMap insert cost; not measured here)"); + println!(); + println!("These numbers are the FLOOR — production state has fatter ops"); + println!("than Count (sketches, windowed). Real recovery throughput in"); + println!("MB/s is similar but per-entry latency is higher."); +} + +#[test] +fn snapshot_decode_deterministic() { + // Two encodes of the same body must produce byte-identical output; + // recovery must produce byte-identical state. Locks the "no + // non-determinism in the snapshot format" contract. + let tmp = TempDir::new().unwrap(); + let body = build_body(500); + + let path1 = write_snapshot(tmp.path(), 1, &body); + let path2 = write_snapshot(tmp.path(), 2, &body); + + let (h1, b1) = SnapshotReader::open(&path1).unwrap(); + let (h2, b2) = SnapshotReader::open(&path2).unwrap(); + + // Bodies must be byte-identical. + assert_eq!( + b1, b2, + "two encodes of same body must produce identical bytes" + ); + // Headers differ on snapshot_lsn + created_at_ms; just verify body lens match. + assert_eq!(h1.body_len, h2.body_len); + + let d1 = SnapshotBody::decode(&b1).unwrap(); + let d2 = SnapshotBody::decode(&b2).unwrap(); + assert_eq!(d1.next_event_id, d2.next_event_id); + assert_eq!( + d1.state_tables["agg_0"].len(), + d2.state_tables["agg_0"].len() + ); +} + +/// Verify that the fork-path snapshot file is decodable AND its body bytes +/// are byte-identical to an in-process encoding of the same input state. +/// +/// We use an empty registry (so both paths emit zero serialized tables); +/// this still locks the contract that the fork path doesn't change the +/// header/format/body schema. +#[cfg(unix)] +#[tokio::test(flavor = "current_thread")] +async fn fork_and_in_process_produce_identical_format() { + use beava_core::registry::Registry; + use beava_server::registry_debug::DevAggState; + use beava_server::snapshot_fork::{do_snapshot_via_fork, ChildExit}; + use beava_server::AppState; + use std::sync::Arc; + + let registry = Arc::new(Registry::new()); + let dev_agg = DevAggState::new(registry); + let (wal_sink, _wal_join) = beava_persistence::WalSink::spawn_no_op(); + let idem_cache = Arc::new(beava_server::idem_cache::IdemCache::new()); + let app_state = AppState::new(dev_agg, wal_sink, idem_cache); + + // Write via the fork path. + let tmp_fork = TempDir::new().unwrap(); + let exit = do_snapshot_via_fork(tmp_fork.path(), 99, &app_state) + .await + .expect("fork-snapshot"); + assert!(matches!(exit, ChildExit::Success { .. })); + let fork_path = tmp_fork.path().join(format!("snapshot-{:016x}.bvs", 99u64)); + + // Build the SAME SnapshotBody in-process and write via SnapshotWriter. + let registry_snap = app_state.dev_agg.registry.snapshot(); + let tables = app_state.dev_agg.state_tables.lock(); + let body_inproc = SnapshotBody::from_live(®istry_snap, &tables, 0, 0); + drop(tables); + let encoded_inproc = body_inproc.encode().expect("encode"); + + let tmp_inproc = TempDir::new().unwrap(); + let inproc_path = SnapshotWriter::write(tmp_inproc.path(), 99, 0, &encoded_inproc).unwrap(); + + // Read both back and compare body bytes (header differs on + // created_at_ms, that's expected). + let (_h_fork, body_fork) = SnapshotReader::open(&fork_path).unwrap(); + let (_h_inproc, body_inproc_read) = SnapshotReader::open(&inproc_path).unwrap(); + assert_eq!( + body_fork, body_inproc_read, + "fork and in-process must produce identical body bytes" + ); +} diff --git a/crates/beava-server/tests/snapshot_write_time.rs b/crates/beava-server/tests/snapshot_write_time.rs new file mode 100644 index 00000000..50d3aff2 --- /dev/null +++ b/crates/beava-server/tests/snapshot_write_time.rs @@ -0,0 +1,103 @@ +//! Direct measurement of snapshot write-time components. +//! +//! Breaks down the wall-clock cost of `do_snapshot` into: +//! 1. encode — `SnapshotBody::encode()` (bincode serialize, CPU-bound) +//! 2. write+fsync — `SnapshotWriter::write` (file IO + sync_all + dir fsync) +//! 3. total — encode + write +//! +//! The legacy path adds (1)+(2) on the snapshot task thread plus the +//! clone-collect under state_tables.lock() (measured separately in +//! `snapshot_lock_contention.rs`). The fork path keeps (1)+(2) in the +//! child process — they don't block the apply thread. + +use beava_core::agg_op::AggOp; +use beava_core::agg_state::CountState; +use beava_core::agg_state_table::EntityKey; +use beava_core::row::Value; +use beava_core::snapshot_body::{ + RegistryDescriptorsOnly, SerializedStateTables, SnapshotBody, SNAPSHOT_BODY_FORMAT_VERSION, +}; +use beava_persistence::SnapshotWriter; +use compact_str::CompactString; +use smallvec::smallvec; +use std::collections::BTreeMap; +use std::time::Instant; +use tempfile::TempDir; + +fn build_body(n: usize) -> SnapshotBody { + let mut entries: Vec<(EntityKey, Vec)> = Vec::with_capacity(n); + for ent in 0..n { + let key_str = format!("user_{ent:09}"); + let entity_key = EntityKey(smallvec![( + CompactString::from("user_id"), + Value::Str(CompactString::from(key_str.as_str())), + )]); + entries.push((entity_key, vec![AggOp::Count(CountState { n: ent as u64 })])); + } + let mut state_tables: SerializedStateTables = BTreeMap::new(); + state_tables.insert("agg_0".to_string(), entries); + SnapshotBody { + body_format_version: SNAPSHOT_BODY_FORMAT_VERSION, + registry: RegistryDescriptorsOnly::default(), + state_tables, + next_event_id: 0, + query_time_ms: 0, + } +} + +#[test] +fn snapshot_write_time_scaling() { + let sizes = [10_000usize, 100_000, 500_000]; + let tmp = TempDir::new().unwrap(); + + println!(); + println!("=== Snapshot WRITE-time breakdown ==="); + println!( + "{:>10} {:>10} {:>10} {:>12} {:>12} {:>10}", + "entries", "bytes_MB", "encode_ms", "write+fsync", "total_ms", "MB/s" + ); + println!("{}", "-".repeat(70)); + + for (i, &n) in sizes.iter().enumerate() { + let body = build_body(n); + // Median of 3 to smooth filesystem cache effects. + let mut samples: Vec<(f64, f64, usize)> = Vec::with_capacity(3); + for trial in 0..3 { + let t0 = Instant::now(); + let encoded = body.encode().expect("encode"); + let encode_ms = t0.elapsed().as_secs_f64() * 1000.0; + + let t1 = Instant::now(); + SnapshotWriter::write( + tmp.path(), + (i * 100 + trial) as u64, + body.registry.version, + &encoded, + ) + .expect("write"); + let write_ms = t1.elapsed().as_secs_f64() * 1000.0; + + samples.push((encode_ms, write_ms, encoded.len())); + } + samples.sort_by(|a, b| (a.0 + a.1).partial_cmp(&(b.0 + b.1)).unwrap()); + let (encode_ms, write_ms, bytes) = samples[1]; + let total = encode_ms + write_ms; + let mb = bytes as f64 / (1024.0 * 1024.0); + let mbps = mb / (total / 1000.0); + + println!( + "{:>10} {:>7.1} MB {:>7.2}ms {:>9.2}ms {:>9.2}ms {:>8.1}", + n, mb, encode_ms, write_ms, total, mbps + ); + } + + println!(); + println!("Notes:"); + println!("- encode is CPU-bound (bincode serialize); release ~1 GB/s, debug ~3-5×"); + println!( + "- write+fsync is disk-bound: header write + body write + sync_all + rename + dir fsync" + ); + println!("- on SSD ~500 MB/s sequential write; on slow containerized volumes much less"); + println!("- LEGACY path: also pays state_tables.lock() clone-collect upstream of these"); + println!("- FORK path: encode + write happen in child; parent's apply thread untouched"); +} diff --git a/crates/beava-server/tests/wal_recovery_corrupt_records.rs b/crates/beava-server/tests/wal_recovery_corrupt_records.rs index 01a393e7..66743eab 100644 --- a/crates/beava-server/tests/wal_recovery_corrupt_records.rs +++ b/crates/beava-server/tests/wal_recovery_corrupt_records.rs @@ -14,6 +14,7 @@ #![cfg(feature = "testing")] +use beava_core::wire::{CT_JSON, CT_MSGPACK}; use beava_server::testing::TestServerBuilder; use std::fs; use std::io::Write; @@ -21,8 +22,8 @@ use std::path::Path; /// Encode one v=2 record into a buffer. /// -/// `body_format` selects the on-disk encoding: `0x02 = CT_JSON` (server -/// default for HTTP /push), `0x01 = CT_MSGPACK`. +/// `body_format` selects the on-disk encoding: `CT_JSON` (server default for +/// HTTP /push) or `CT_MSGPACK`. fn encode_v2_record( buf: &mut Vec, body_format: u8, @@ -58,7 +59,6 @@ fn write_wal_file(dir: &Path, bytes: &[u8]) { /// the corrupt body) and then warn-skip the corrupt body via the /// `serde_json::from_slice` failure arm. fn build_wal_with_one_valid_and_one_corrupt_json() -> Vec { - const CT_JSON: u8 = 0x02; let mut buf = Vec::new(); // Record 1: valid CT_JSON body — `{"user_id":"alice","amount":1.0}`. @@ -79,8 +79,6 @@ fn build_wal_with_one_valid_and_one_corrupt_json() -> Vec { /// record. Exercises the `recovery.v2_msgpack_decode_failed` arm /// (recovery.rs:251-260). fn build_wal_with_corrupt_msgpack_record() -> Vec { - const CT_JSON: u8 = 0x02; - const CT_MSGPACK: u8 = 0x01; let mut buf = Vec::new(); // Record 1: valid CT_JSON. @@ -235,7 +233,6 @@ async fn boot_with_only_corrupt_record_still_boots() { // Single CORRUPT CT_JSON record — declared body_len=5 but body is // not valid JSON. - const CT_JSON: u8 = 0x02; let mut buf = Vec::new(); encode_v2_record(&mut buf, CT_JSON, 1, 1_700_000_000_000, "Txn", b"xxxxx"); write_wal_file(wal.path(), &buf);