adopt the tracing log facade, engine crates only (review 004 item 7's family-level decision, ADR-025): the family precedent checked and unanimous (alkcall/alktunnels/alksocks/alktty all on tracing = "0.1" facade-only, tracing-subscriber env-filter a dev-dep where present, silent by default); user sign-off taken in-session (2026-10-11, adopt-tracing option chosen) and recorded in the ADR's status; core stays dep- and emit-free (the explicit core-dep answer — the payload serde deps remain the sole core deps, the ADR states the ADR-020-§4 reading explicitly); all 19 library-path eprintln! sites migrated to tracing::warn!/error! with message text + the alkstore: prefix + the secret-free discipline unchanged (17 at review time, +2 from the review's own inline tick/lease restructures — re-grepped, sqlite 10 / pg 9, zero remainder, tests' harness-skip prints untouched); levels: warn = retried/degraded ops, error = unrecoverable loss (watcher death, discarded pooled clients, panic-path rollback failures); the four substrate-lineage files ride PROVENANCE delta D-41 (message-identical macro swap); deployment.md gains the diagnostics-posture section (operator recipe RUST_LOG=warn/error at the consuming binary; listener application_name diagnosability joins it), ADR index + design-decisions table carry the 025 row, CHANGELOG's 0.1.0 body states the facade; pg-fix-forwarder-diagnosability's output form now pinned (warn on failed reconnect connects with attempt/backoff context, error on the loop-exit poll error); gates green: build, workspace tests server-less, clippy -D warnings, fmt, doc gate zero warnings, fuzz corpus replay 6/6; task -> completed
This commit is contained in:
1 parent
ce5da852ca
commit
a9b6cf0c86
19 files changed
+332
-31
No files matched your search
@@ -16,6 +16,7 @@ rusqlite = { version = "0.40", features = ["bundled", "functions"] }
|
||||
serde_json = "1"
|
||||
thiserror = "2"
|
||||
tokio = { version = "1", features = ["rt", "sync", "time"] }
|
||||
tracing = "0.1"
|
||||
|
||||
# file-id only supports unix and windows. Other targets (WASI, Redox,
|
||||
# illumos, etc.) get the `(0, 0)` fallback in substrate::watcher's
|
||||
|
||||
@@ -133,6 +133,7 @@ Cherry-picks: empty at scaffold, append-only forever.
|
||||
| D-38 | port delta | degenerate/adversarial-triple hardening on `skip_forward` (two legs, both aligning to the pg engine's committed clamp shape where it existed and extending pg itself): (1) the `interval` is clamped (`interval.max(1) as i128`) — pre-fix, `interval == 0` panicked on i128 division-by-zero, reachable only through degenerate/non-grammar callers (the parsers reject `n <= 0`, so every engine-internal call site passes `interval >= 1`); (2) the gap is computed in i128 (`now as i128 - next_fire_at as i128`) — pre-fix, `now - next_fire_at` was an **i64 subtraction** that panics in debug (overflow) / silently wraps in release when `(next_fire_at, now)` straddle the full domain (`now=i64::MIN`-adjacent, `next_fire_at=i64::MAX`-adjacent), feeding a wrapped gap to the 128-bit arithmetic and breaking the saturation guarantee. Found by the `every_parse` differential target (wave 7, tasks/fuzz-target-every-parse) driving the adversarial `(next_fire_at, now, interval)` space; pg needed leg (2) as well. Observable behavior unaffected in the reachable domain (|gap| < i64 range), saturation posture now holds over the whole domain. Zero signature change; lineage body untouched (`skip_forward` is the re-derived scheduler half, D-12's own) | `queue_ops.rs` (`skip_forward`, two lines) | docs/research/fuzzing.md §3.2 (the overflow-posture invariant: reject-or-saturate, never wrap or panic, over the whole domain); wave-6's register-overflow alignment (tasks/review-wave-6); alkstore-postgres/src/scheduler.rs `skip_forward` (the pinned clamp shape) | ours |
|
||||
| D-39 | port delta | watcher-death state machine (review 004 items 2+3, two legs on the ported watcher): (1) **identity-unknown baseline** — the loop's initial identity `stat` failure seeds an unknown baseline instead of the false `(0, 0)`; the first *successful* stat captures it without driving the death path (pre-fix, a transient startup stat hiccup killed the watcher — and closed every subscriber — when the first later stat succeeded); (2) **dead-watcher fail-closed subscribe** — the loop sets a `dead` sign on the caller (`SharedUpdateWatcher`, an `Arc<AtomicBool>`) before exiting through the watcher-fatal path, and `subscribe` becomes fallible, failing closed on the sign (or a taken watcher slot) checked atomically with the enrollment under the senders lock — new subscriptions after a death fail instead of enrolling onto a feed with no poller alive to park forever (the death-guard's clear of *pre-death* subscribers unchanged, D-07 still holds); the engine maps the failure into `Error::Database` at `listen`/stream `subscribe` (ADR-008 §5's opaque fallback). Lineage behavior for both legs was the (0,0)-seed and the infallible enroll | `watcher.rs` (`run_poll_loop`'s baseline/identity arms, `SharedUpdateWatcher`'s dead sign + fallible `subscribe`); `notify.rs`/`stream.rs` (the engine-side mapping) | engine-sqlite.md's watcher-death posture ("new subscriptions fail closed"; identity unknown until the first successful stat); review 004 items 2–3 (tasks/sqlite-fix-watcher-death-subscribe); ADR-006 (the close/fail-closed posture); ADR-012 §4 (delta discipline; D-07's death path refined) | ours |
|
||||
| D-40 | hygiene | `// SAFETY` comments installed at all ten `unsafe { ctx.get_connection() }` UDF sites — the eight `attach_alkstore_functions` registrations (stream/lock function set + `alkstore_bootstrap`), the `notify` registration in `attach_notify`, and the savepoint-panic scalar probe in `ops.rs`'s test module. Review 004 item 15 scoped the eight; the two others are the same class (identical rusqlite registration shape, same single-connection synchronous invocation) and joined the same delta. Each comment states the concrete soundness invariant — the UDF is registered on one connection and invoked only as a synchronous callback inside a statement on that very connection (SQLite hands back that handle mid-statement); each connection is one-thread-at-a-time so the cross-thread-alias hazard in rusqlite #643 cannot arise (rusqlite's `Connection` is !Sync; the reader pool transfers owned connections, the writer lease is exclusive); and the closure consumes the deref'd reference only within the callback's lifetime (nothing stored past return, no owned access, no close). Comment-only: zero behavior change. The deliberate D-15 exception — comments riding a delta, not a casual edit | `ops.rs` (the eight `attach_alkstore_functions` blocks + the test-module probe), `schema.rs` (`attach_notify`) | AGENTS.md's inline-comment carve-out ("when a non-obvious safety constraint would otherwise be missed"); review 004 §"Findings recorded, not fixed" item 15; rusqlite 0.40 `Context::get_connection` contract (functions.rs; issue #643) | ours |
|
||||
| D-41 | port delta | the substrate's eight `eprintln!` diagnostics sites routed through the `tracing` facade ([ADR-025](../../../docs/architecture/decisions/025-log-facade.md)): `watcher.rs`'s six (watcher connect/identity/poll/reconnect failures — `warn`; db-file-replacement death — `error`), `schema.rs`'s one (writer-slot replenish failure — `warn`), `ops.rs`'s one (panic-unwind SAVEPOINT undo failure — `error`). Message text, `alkstore:` prefix discipline, and the secret-free rule carry over unchanged; only the macro changes (`eprintln!` → `tracing::warn!`/`error!`, fully qualified — no import churn). Zero emission-content change: identical strings on the same conditions; with no subscriber installed the events drop (silent) where `eprintln!` printed — the facade's documented default ([ADR-025] §Decision). Upstream emitted the same class through `eprintln!`; the facade adoption is ours | `watcher.rs` (six sites in `run_poll_loop`), `schema.rs` (`replenish`), `ops.rs` (`UnwindUndo::drop`) | ADR-025 (the adoption; all sites migrate, no `eprintln!` remainder); review 004 item 7 (the posture's finding); the family posture (`tracing` facade-only) | ours |
|
||||
|
||||
### Cherry-picks
|
||||
|
||||
|
||||
@@ -92,7 +92,7 @@ impl Drop for UnwindUndo<'_> {
|
||||
}
|
||||
let failures = undo_savepoint_frame(self.conn, self.name, self.owns_transaction);
|
||||
if !failures.is_empty() {
|
||||
eprintln!(
|
||||
tracing::error!(
|
||||
"alkstore: error: undoing SAVEPOINT {} after a panic left the \
|
||||
connection in an unknown state: {}",
|
||||
self.name,
|
||||
|
||||
@@ -387,7 +387,7 @@ impl Writer {
|
||||
}
|
||||
match open_conn_bootstrapped(&self.path) {
|
||||
Ok(fresh) => self.release(fresh),
|
||||
Err(e) => eprintln!(
|
||||
Err(e) => tracing::warn!(
|
||||
"alkstore: error: writer slot replenish after an abandoned \
|
||||
operation failed to open a fresh connection: {e}"
|
||||
),
|
||||
|
||||
@@ -161,7 +161,7 @@ pub(crate) fn run_poll_loop<F>(
|
||||
let mut conn = match open_conn_fn(&db_path) {
|
||||
Ok(c) => Some(c),
|
||||
Err(e) => {
|
||||
eprintln!("alkstore: failed to open watcher connection: {e}");
|
||||
tracing::warn!("alkstore: failed to open watcher connection: {e}");
|
||||
None
|
||||
}
|
||||
};
|
||||
@@ -177,7 +177,7 @@ pub(crate) fn run_poll_loop<F>(
|
||||
let mut baseline = match stat_identity(&db_path) {
|
||||
Ok(id) => Some(id),
|
||||
Err(e) => {
|
||||
eprintln!("alkstore: failed to stat database for identity check: {e}");
|
||||
tracing::warn!("alkstore: failed to stat database for identity check: {e}");
|
||||
None
|
||||
}
|
||||
};
|
||||
@@ -199,7 +199,7 @@ pub(crate) fn run_poll_loop<F>(
|
||||
}
|
||||
Err(e) if is_transient_lock_error(&e) => {}
|
||||
Err(e) => {
|
||||
eprintln!("alkstore: data_version poll failed: {e}");
|
||||
tracing::warn!("alkstore: data_version poll failed: {e}");
|
||||
conn = None;
|
||||
on_change();
|
||||
}
|
||||
@@ -214,7 +214,7 @@ pub(crate) fn run_poll_loop<F>(
|
||||
conn = Some(c);
|
||||
}
|
||||
Err(e) => {
|
||||
eprintln!("alkstore: reconnect failed: {e}");
|
||||
tracing::warn!("alkstore: reconnect failed: {e}");
|
||||
}
|
||||
}
|
||||
}
|
||||
@@ -227,13 +227,17 @@ pub(crate) fn run_poll_loop<F>(
|
||||
Ok(current) => match baseline {
|
||||
Some(expected) => {
|
||||
if current != expected {
|
||||
eprintln!(
|
||||
tracing::error!(
|
||||
"alkstore: database file replaced: \
|
||||
expected (dev={}, ino={}), \
|
||||
found (dev={}, ino={}) at {:?}. \
|
||||
The watcher cannot recover; it has stopped and \
|
||||
closed all subscribers; close the store and reopen.",
|
||||
expected.0, expected.1, current.0, current.1, db_path
|
||||
expected.0,
|
||||
expected.1,
|
||||
current.0,
|
||||
current.1,
|
||||
db_path
|
||||
);
|
||||
dead.store(true, Ordering::Release);
|
||||
return;
|
||||
@@ -242,7 +246,7 @@ pub(crate) fn run_poll_loop<F>(
|
||||
None => baseline = Some(current),
|
||||
},
|
||||
Err(e) => {
|
||||
eprintln!("alkstore: stat identity check failed: {e}");
|
||||
tracing::warn!("alkstore: stat identity check failed: {e}");
|
||||
conn = None;
|
||||
on_change();
|
||||
}
|
||||
|
||||
@@ -189,7 +189,7 @@ impl Drop for ConnLease {
|
||||
#[cfg(not(test))]
|
||||
let rolled_back = conn.execute_batch("ROLLBACK");
|
||||
if let Err(rollback) = rolled_back {
|
||||
eprintln!(
|
||||
tracing::error!(
|
||||
"alkstore: error: rollback on a cancelled transaction op \
|
||||
left the connection in an unknown state: {rollback}"
|
||||
);
|
||||
@@ -470,7 +470,7 @@ impl Drop for SqliteTxHandle {
|
||||
match rolled_back {
|
||||
Ok(()) => self.writer.release(conn),
|
||||
Err(rollback) => {
|
||||
eprintln!(
|
||||
tracing::error!(
|
||||
"alkstore: error: rollback on a dropped transaction handle \
|
||||
left the connection in an unknown state: {rollback}"
|
||||
);
|
||||
|
||||
Reference in new issue
Block a user