//! The diagnostics event store: a curated log of operational failure episodes. //! //! An *episode* is one subject failing continuously. The first failure opens a //! row, every repeat bumps its `occurrences` and `last_seen`, and the first //! success closes it. A subject that fails again later opens a **new** row, so //! the history reads as a sequence of episodes rather than one row whose meaning //! keeps changing. `operational_events` in `config.db` holds them, and //! `repositories/events_repo.zig` owns the SQL. //! //! Three properties shape everything below. //! //! **A diagnostics failure must never break the subsystem reporting it.** Every //! producer-facing mutation returns `void`. A `db.Error` sets a latch, counts, //! and drops the event. Operator-requested mutations (`purge`, `purgeAll`) are //! not producers: they latch the same way but return the error, because an //! operator told "nothing happened" on a failed delete is the lie the latch //! exists to prevent. `init` also returns the error, and the //! composition root runs with no store at all, because a store built on a mirror //! it could not verify would answer resolves with confident no-ops — worse than //! having no store. //! //! **Time is a parameter, not a seam.** Every method that stamps a row takes //! `now_s` (`purge`/`purgeAll` only delete, so they take none), matching //! `storage/logger.zig`. Production callers read `Clock.real`; tests pass literals. There is no clock in here and no //! function pointer standing in for one. //! //! **`resolve` is on the DNS hot path.** `pool.recordSuccess` calls it after //! every successful exchange, so the steady state — nothing wrong, nothing to //! close — must cost a mutex acquire and a lookup in the in-memory mirror, and //! must issue no SQL at all. `ActiveSet` and `untracked_active_count` exist to //! make that guarantee exact rather than probable. const std = @import("std"); const builtin = @import("builtin"); const db = @import("db.zig"); const events_repo = @import("repositories/events_repo.zig"); const log = std.log.scoped(.events); /// Every failure episode nxdns can **emit**, and nothing else. **The enum is /// the truth** about what a running process writes: the exhaustive tests count /// it, and the dotted string is only its wire form. /// /// It is not the whole documented union. The API and the frontend copy map hold /// these plus `legacy_wire_codes`, because a stored row outlives its producer — /// see there. A code whose producer is gone moves to that list rather than /// staying here: a member here is a code `Store.report` accepts, and a report /// under a dead code opens an episode nothing can ever resolve. pub const Code = enum { disk_space, disk_probe, blocklist_refresh, blocklist_snapshot, blocklist_storage, certificate_reload, query_log_write, query_log_maintenance, query_log_recreated, upstream_exchange, client_names_storage, clients_storage, listener_start, configuration_load, }; /// The stored and wire form. An exhaustive switch rather than a `@tagName` /// transform: the mapping is a contract with the frontend and with every stored /// row, so renaming an enum member must be a compile error here rather than a /// silent change to what past rows mean. pub fn wire(code: Code) []const u8 { return switch (code) { .disk_space => "disk.space", .disk_probe => "disk.probe", .blocklist_refresh => "blocklist.refresh", .blocklist_snapshot => "blocklist.snapshot", .blocklist_storage => "blocklist.storage", .certificate_reload => "certificate.reload", .query_log_write => "query_log.write", .query_log_maintenance => "query_log.maintenance", .query_log_recreated => "query_log.recreated", .upstream_exchange => "upstream.exchange", .client_names_storage => "client_names.storage", .clients_storage => "clients.storage", .listener_start => "listener.start", .configuration_load => "configuration.load", }; } /// The subsystem a code belongs to, and the value the API's `component` filter /// matches. Exhaustive for the same reason `wire` is. pub fn component(code: Code) []const u8 { return switch (code) { .disk_space, .disk_probe => "disk", .blocklist_refresh, .blocklist_snapshot, .blocklist_storage => "blocklist", .certificate_reload => "certificate", .query_log_write, .query_log_maintenance, .query_log_recreated => "query_log", .upstream_exchange => "upstream", .client_names_storage => "client_names", .clients_storage => "clients", .listener_start => "listener", .configuration_load => "configuration", }; } /// Wire codes that stored rows still carry and no code emits. /// /// They live as text, not as `Code` members, because the read path is the only /// path that meets them: the list endpoint passes a stored code straight /// through, and `events_repo.componentOf` derives the component from the text. /// The one thing the store must still do with them is close whatever a past /// release left open — see `Store.init`. /// /// The documented event-code union is these plus every `Code`, which is what /// keeps a real response describing an old row inside the contract. pub const legacy_wire_codes = [_][]const u8{ // Milestone 30 deleted the upstream-minute history subsystem. "upstream_history.write", }; /// Fixed per emit call, not per code: the same disk monitor reports a /// transition to `warn` as a warning and one to `critical` as an error. /// /// There is deliberately no `info`. An event is something an operator may have /// to act on; anything below that belongs in the journal, which keeps the raw /// stream either way. pub const Severity = enum { warning, @"error", /// The stored and wire form. The "raise, never lower" rule an episode's /// severity follows is not here: it lives in `events_repo`'s `UPDATE`, so /// it holds in one statement rather than in a read-modify-write. pub fn text(self: Severity) []const u8 { return @tagName(self); } }; /// Re-exported so callers need one import. The read types belong to the /// repository, which owns the columns they mirror. pub const Event = events_repo.Event; pub const Filter = events_repo.Filter; pub const State = events_repo.State; pub const Counts = events_repo.Counts; pub const PurgeOutcome = events_repo.PurgeOutcome; pub const max_limit = events_repo.max_limit; /// One page of `GET /api/diagnostics`, exactly as it serializes. pub const EventsPage = struct { events: []const Event, /// The cursor for the next page, or null when this page is the last one. next_before: ?i64, /// Computed in the same lock as `events`, so a page cannot show a count /// that disagrees with the rows beside it. active: Counts, }; /// Counting repository calls is how the "a no-op resolve executes no SQL" /// guarantee is *tested* rather than asserted. `sqlite3_total_changes` cannot /// do it: a `SELECT` probe moves no rows, so a slow path that only read would /// look identical to one that never ran. const track_statements = builtin.mode == .Debug; pub const Store = struct { pub const max_detail_len = 512; /// Keys at or under this are stored verbatim; longer ones become /// `sha256:` digests. See `canonicalKey`. pub const max_subject_key_len = events_repo.key_capacity; pub const max_subject_label_len = 128; /// Ninety days of resolved history, and a hard row cap under it. Neither is /// configurable (milestone anti-requirement): this is a curated log, and an /// operator who wants more has the journal. pub const resolved_retention_s: i64 = 90 * 86_400; pub const max_resolved_rows: i64 = 5_000; /// How many active episodes the in-memory mirror holds. Beyond it, active /// rows exist that `resolve` cannot see, and `untracked_active_count` is /// what keeps that exact rather than guessed. pub const mirror_capacity = 256; /// The most kept keys one `resolveExcept` may carry. The boot-finalized /// callers pass the endpoints and settings that failed *this boot* — a /// handful — and the bound is what keeps the canonicalization buffer on the /// stack. Over it, the call is refused and counted rather than silently /// truncated: resolving more than the caller meant would close episodes /// that are still true. pub const max_kept_keys = 64; mutex: std.Io.Mutex = .init, /// A dedicated connection. **Every** access goes through `mutex`, including /// the API reads, so nothing outside this file ever touches it. database: *db.Db, /// Latched on the first failed write and cleared by the next success. The /// health endpoint reports it; nothing polls for it. write_failed: std.atomic.Value(bool) = .init(false), write_failures: std.atomic.Value(u64) = .init(0), active: ActiveSet = .{}, /// Active rows that are **not** in the mirror. Exact: `init` computes it as /// the difference, `report` grows it only when it inserts a row it cannot /// mirror, and `resolve` shrinks it only when a slow path really closed /// one. untracked_active_count: u32 = 0, statements: if (track_statements) u64 else void = if (track_statements) 0 else {}, /// Loads the mirror and the overflow count. A failure here reaches the /// caller because a `Store` whose mirror is unverified would answer /// `resolve` with a no-op for episodes that are really open — silently /// wrong, where no store at all is merely absent and says so through /// `/api/health`. /// /// Prunes on the way in, which is why it takes `now_s` like every other /// method here: retention that only ran while the process happened to stay /// up would never catch a box that is restarted daily. pub fn init(io: std.Io, database: *db.Db, now_s: i64) db.Error!Store { var store: Store = .{ .database = database }; // Before the mirror load and the prune, both of which would otherwise // read a state this is about to change: an episode left open here would // sit in the mirror forever and hold `untracked_active_count` above // zero, and one resolved after the prune would keep its row for another // ninety days. `now_s` is the resolution time on purpose — the store's // own open time, not the episode's stale `last_seen`, which a database // older than the retention window would prune in this very call. for (legacy_wire_codes) |code| { _ = try events_repo.resolveActiveByCode(database, now_s, code); } var chunk: [16]events_repo.ActiveRow = undefined; var after: i64 = 0; while (store.active.len < mirror_capacity) { const room = @min(chunk.len, mirror_capacity - store.active.len); const got = try events_repo.loadActive(database, chunk[0..room], after); if (got == 0) break; for (chunk[0..got]) |*row| { const code = parseWire(row.code()) orelse continue; // The loop stops at `mirror_capacity`, so this cannot be a // rejection; the untracked count below covers whatever did not fit. _ = store.active.put(code, digestOf(row.subjectKey()), row.id); } after = chunk[got - 1].id; } const total_active = try events_repo.countActive(database); store.untracked_active_count = @intCast(@max(0, total_active - @as(i64, store.active.len))); // One fallible step: load and prune fail together. A database that // cannot prune at startup is a database this store must not be built // on — `app.zig` runs with no store and says so. _ = try events_repo.pruneResolved( database, now_s - resolved_retention_s, max_resolved_rows, ); _ = io; return store; } /// Records a failure of `subject_key` under `code`. /// /// Open episode → `last_seen`, `occurrences`, `detail` and a severity that /// can only rise. No open episode → a new one. pub fn report( self: *Store, io: std.Io, now_s: i64, code: Code, subject_key: []const u8, subject_label: []const u8, severity: Severity, detail: []const u8, ) void { var key_buf: [max_subject_key_len]u8 = undefined; const key = canonicalKey(subject_key, &key_buf); const label = truncate(subject_label, max_subject_label_len); const text = truncate(detail, max_detail_len); const digest = digestOf(key); self.mutex.lockUncancelable(io); defer self.mutex.unlock(io); if (self.active.find(code, digest)) |entry| { self.count(); const touched = events_repo.touchActive(self.database, entry.id, now_s, severity.text(), text) catch |err| return self.recordFailure(err); self.recordSuccess(); if (touched) return; // The mirror pointed at a row that is gone or already closed. // Dropping the stale entry lets the insert below open the episode // this failure really is. self.active.remove(entry); } // A miss with nothing outside the mirror means there is provably no // open episode for this subject, so the insert cannot collide. if (self.untracked_active_count != 0) { self.count(); if (events_repo.selectActiveId(self.database, wire(code), key) catch |err| return self.recordFailure(err)) |id| { self.count(); _ = events_repo.touchActive(self.database, id, now_s, severity.text(), text) catch |err| return self.recordFailure(err); self.recordSuccess(); return; } } self.count(); const id = events_repo.insertActive( self.database, now_s, wire(code), key, label, severity.text(), text, ) catch |err| return self.recordFailure(err); self.recordSuccess(); if (!self.active.put(code, digest, id)) self.untracked_active_count += 1; } /// Opens the episode of `subject_key` when none is open, and restates the /// severity and the detail of the one that is. /// /// The projection counterpart of `report`. A reconciliation asserts the /// state an endpoint is in now; it is not a new observation, so it must not /// raise `occurrences` or move `last_seen`. It does own the text: a retired /// generation's late report can leave a stale cause on a card the live /// generation still holds open, and this is what restores the true one. /// Only a recorded failure calls `report`. /// /// The open check is a statement rather than a mirror lookup: the mirror is /// a hint that can point at a row that is gone or already closed, and /// `report` recovers from that through the touch it was making anyway. /// There is no write here to learn it from, so this asks. That costs one /// SELECT per reconciled subject, on a path that runs at boot and at a /// generation retirement. pub fn ensureOpen( self: *Store, io: std.Io, now_s: i64, code: Code, subject_key: []const u8, subject_label: []const u8, severity: Severity, detail: []const u8, ) void { var key_buf: [max_subject_key_len]u8 = undefined; const key = canonicalKey(subject_key, &key_buf); const label = truncate(subject_label, max_subject_label_len); const text = truncate(detail, max_detail_len); const digest = digestOf(key); self.mutex.lockUncancelable(io); defer self.mutex.unlock(io); self.count(); const existing = events_repo.selectActiveId(self.database, wire(code), key) catch |err| return self.recordFailure(err); // The read is not what clears the write latch: a `resolveExcept` that // failed a moment ago is still the last word on whether this store can // write, and only a write of our own can answer that. if (existing) |id| { self.count(); _ = events_repo.restateActive(self.database, id, severity.text(), text) catch |err| return self.recordFailure(err); return self.recordSuccess(); } // Nothing is open, so a mirror entry claiming otherwise is stale and // would make the insert below look like a collision. if (self.active.find(code, digest)) |entry| self.active.remove(entry); self.count(); const id = events_repo.insertActive( self.database, now_s, wire(code), key, label, severity.text(), text, ) catch |err| return self.recordFailure(err); self.recordSuccess(); if (!self.active.put(code, digest, id)) self.untracked_active_count += 1; } /// Records that `subject_key` is working again, closing its episode if one /// is open. /// /// **The hot path is the miss.** A mirror miss with nothing untracked means /// no episode can be open, and this returns having issued no statement. pub fn resolve(self: *Store, io: std.Io, now_s: i64, code: Code, subject_key: []const u8) void { var key_buf: [max_subject_key_len]u8 = undefined; const key = canonicalKey(subject_key, &key_buf); const digest = digestOf(key); self.mutex.lockUncancelable(io); defer self.mutex.unlock(io); if (self.active.find(code, digest)) |entry| { self.count(); _ = events_repo.resolveActive(self.database, entry.id, now_s) catch |err| return self.recordFailure(err); self.recordSuccess(); self.active.remove(entry); return; } if (self.untracked_active_count == 0) return; self.count(); const closed = events_repo.resolveActiveByKey(self.database, now_s, wire(code), key) catch |err| return self.recordFailure(err); self.recordSuccess(); if (closed) self.untracked_active_count -= 1; } /// Records something that happened once and is already over — the one-shot /// events, `query_log.recreated` among them. The row is written resolved, /// so it never becomes an open episode and never touches the mirror. pub fn reportResolved( self: *Store, io: std.Io, now_s: i64, code: Code, subject_key: []const u8, subject_label: []const u8, severity: Severity, detail: []const u8, ) void { var key_buf: [max_subject_key_len]u8 = undefined; const key = canonicalKey(subject_key, &key_buf); self.mutex.lockUncancelable(io); defer self.mutex.unlock(io); self.count(); events_repo.insertResolved( self.database, now_s, wire(code), key, truncate(subject_label, max_subject_label_len), severity.text(), truncate(detail, max_detail_len), ) catch |err| return self.recordFailure(err); self.recordSuccess(); } /// Closes every open episode of `code` whose subject is not in `kept_keys`. /// /// For the boot-finalized codes (`listener.start`, `configuration.load`): /// after the boot phase that can produce them finishes, one call closes /// whatever the last boot left open and this boot did not repeat. /// /// And for one episodic code, `blocklist.refresh`, where the subject itself /// can be deleted: a blocklist source removed through the API or dropped by /// a config import can never succeed again, so a success cannot be what /// closes its episode. `Manager.resolveDeletedSources` passes the key of /// every source that still exists, and the caller's rule is what makes that /// safe — the kept list must be the *whole* current subject set, never a /// filtered part of it. For every other episodic code, a success is what /// closes an episode and this must not be used. pub fn resolveExcept( self: *Store, io: std.Io, now_s: i64, code: Code, kept_keys: []const []const u8, ) void { var canonical_storage: [max_kept_keys][max_subject_key_len]u8 = undefined; var canonical: [max_kept_keys][]const u8 = undefined; self.mutex.lockUncancelable(io); defer self.mutex.unlock(io); if (kept_keys.len > max_kept_keys) { // Refused, counted and latched rather than truncated: a shortened // kept list would resolve episodes that are still true. return self.recordFailure(error.TooBig); } for (kept_keys, 0..) |key, i| { canonical[i] = canonicalKey(key, &canonical_storage[i]); } self.count(); const total_active = events_repo.resolveExcept( self.database, now_s, wire(code), canonical[0..kept_keys.len], ) catch |err| return self.recordFailure(err); self.recordSuccess(); // The transaction committed, so the mirror can be brought into line // with it: everything of this code except the kept keys is closed. self.active.retain(code, canonical[0..kept_keys.len]); self.untracked_active_count = @intCast(@max(0, total_active - @as(i64, self.active.len))); } /// A caller that collected more kept keys than `max_kept_keys` cannot call /// `resolveExcept` at all — it has no argument to pass that would be true. /// It refuses here instead, so the refusal is counted and latched exactly /// like the one `resolveExcept` makes on its own argument, rather than /// disappearing as a skipped finalize. /// `now_s` for the same reason every mutating entry point here takes it: /// the caller owns the clock, even on the path that writes nothing. pub fn refuseResolveExcept(self: *Store, io: std.Io, now_s: i64) void { _ = now_s; self.mutex.lockUncancelable(io); defer self.mutex.unlock(io); self.recordFailure(error.TooBig); } /// The operator's manual delete of one resolved event /// (`DELETE /api/diagnostics/{id}`). Resolution stays automatic; when the /// history disappears is the operator's call. /// /// **The mirror is not touched, and must not need to be.** Only a row with /// `resolved_at IS NOT NULL` can go, and such a row is by definition not in /// `active` and not counted in `untracked_active_count` — both describe open /// episodes only. `events_repo.purgeResolved` enforces that in SQL rather /// than trusting the caller. /// /// The failure reaches the caller, unlike the emitter-facing writes above: a /// request asked for this, and an operator who is told nothing happened must /// be told it failed rather than shown a row that quietly stayed. The latch /// and the counter still move, because this is a write like any other and /// `/api/health` reports whether writes are landing. pub fn purge(self: *Store, io: std.Io, id: i64) db.Error!PurgeOutcome { self.mutex.lockUncancelable(io); defer self.mutex.unlock(io); self.count(); const outcome = events_repo.purgeResolved(self.database, id) catch |err| { self.recordFailure(err); return err; }; self.recordSuccess(); return outcome; } /// `DELETE /api/diagnostics` — every resolved event at once, returning how /// many went. Active episodes are never candidates, for the reason `purge` /// gives: the mirror describes open rows and this deletes only closed ones. pub fn purgeAll(self: *Store, io: std.Io) db.Error!i64 { self.mutex.lockUncancelable(io); defer self.mutex.unlock(io); self.count(); const purged = events_repo.purgeAllResolved(self.database) catch |err| { self.recordFailure(err); return err; }; self.recordSuccess(); return purged; } /// Drops resolved rows past the retention window and past the row cap. /// Active episodes are never pruned: an episode still going is the state of /// the box, not history. pub fn prune(self: *Store, io: std.Io, now_s: i64) void { self.mutex.lockUncancelable(io); defer self.mutex.unlock(io); self.count(); _ = events_repo.pruneResolved( self.database, now_s - resolved_retention_s, max_resolved_rows, ) catch |err| return self.recordFailure(err); self.recordSuccess(); } /// True while the last write attempt failed. `/api/health` reports it as /// `unavailable` and degrades on it — a diagnostics log that is not /// recording is exactly the condition an operator cannot otherwise see. pub fn writeFailed(self: *const Store) bool { return self.write_failed.load(.monotonic); } /// Feeds `nxdns_diagnostics_write_failures_total`. pub fn writeFailures(self: *const Store) u64 { return self.write_failures.load(.monotonic); } pub fn activeCounts(self: *Store, io: std.Io) Counts { self.mutex.lockUncancelable(io); defer self.mutex.unlock(io); self.count(); // A read neither sets nor clears the write latch: the latch says // whether writes are landing, and a health scrape is not a write. return events_repo.activeCounts(self.database) catch |err| { log.warn("diagnostics active counts failed: {s}", .{@errorName(err)}); return .{}; }; } /// One page of the API, cursor and active counts included. A read failure /// *does* reach the caller: the handler turns it into a 500, and a page that /// silently answered "no events" would be the one lie this whole feature /// exists to prevent. pub fn selectEvents( self: *Store, io: std.Io, arena: std.mem.Allocator, filter: Filter, ) db.Error!EventsPage { self.mutex.lockUncancelable(io); defer self.mutex.unlock(io); self.count(); const rows = try events_repo.selectEvents(self.database, arena, filter); self.count(); const counts = try events_repo.activeCounts(self.database); // A full page carries a cursor and a short one does not, so a client // stops when `next_before` is null without a count query. const full = rows.items.len == @min(filter.limit, max_limit); return .{ .events = rows.items, .next_before = if (full and rows.items.len != 0) rows.items[rows.items.len - 1].id else null, .active = counts, }; } pub fn selectOne(self: *Store, io: std.Io, arena: std.mem.Allocator, id: i64) db.Error!?Event { self.mutex.lockUncancelable(io); defer self.mutex.unlock(io); self.count(); return events_repo.selectOne(self.database, arena, id); } /// **Logs only on the `false → true` transition.** A broken diagnostics /// database plus a busy resolver would otherwise produce a warning at query /// rate; the counter and `/api/health` carry the ongoing state. fn recordFailure(self: *Store, err: anyerror) void { _ = self.write_failures.fetchAdd(1, .monotonic); if (!self.write_failed.swap(true, .monotonic)) { log.warn( "diagnostics store write failed ({s}); further failures are counted, not logged", .{@errorName(err)}, ); } } fn recordSuccess(self: *Store) void { if (self.write_failed.swap(false, .monotonic)) { log.info("diagnostics store is recording again", .{}); } } /// Called immediately before every repository call, under the mutex. fn count(self: *Store) void { if (track_statements) self.statements += 1; } }; /// `subject_key` identity, exact at any length. /// /// A key at or under `Store.max_subject_key_len` is stored verbatim. A longer /// one — operator urls are unbounded, `safe_url.zig` imposes no input limit — /// becomes `"sha256:" ++ hex(SHA-256(key))`: 71 bytes, deterministic, and /// collision-free in practice, so two distinct long urls never merge into one /// episode and the same url always maps back to the same one. /// /// Never truncated and never rejected. Truncation is what would make two /// different subjects share an episode, and rejection would drop the event of /// exactly the subject whose name is unusual. pub fn canonicalKey(key: []const u8, buf: *[Store.max_subject_key_len]u8) []const u8 { if (key.len <= Store.max_subject_key_len) { @memcpy(buf[0..key.len], key); return buf[0..key.len]; } const prefix = "sha256:"; var raw: [std.crypto.hash.sha2.Sha256.digest_length]u8 = undefined; std.crypto.hash.sha2.Sha256.hash(key, &raw, .{}); @memcpy(buf[0..prefix.len], prefix); const hex = std.fmt.bytesToHex(raw, .lower); @memcpy(buf[prefix.len..][0..hex.len], &hex); return buf[0 .. prefix.len + hex.len]; } /// The mirror's identity for a canonical key. The digest rather than the bytes: /// 256 verbatim keys would be 64 KiB of mirror on the composition root's stack, /// and the comparison is exact either way. fn digestOf(key: []const u8) [32]u8 { var out: [32]u8 = undefined; std.crypto.hash.sha2.Sha256.hash(key, &out, .{}); return out; } fn truncate(value: []const u8, limit: usize) []const u8 { return value[0..@min(value.len, limit)]; } /// The wire code back to its enum member, or null for text no version of this /// program wrote. Used only when loading the mirror: an unrecognised row stays /// active and untracked, which is the honest reading of "this process does not /// know what that is". fn parseWire(text: []const u8) ?Code { inline for (comptime std.enums.values(Code)) |code| { if (std.mem.eql(u8, text, wire(code))) return code; } return null; } /// The in-memory mirror of active `(code, subject_key)` rows. /// /// A flat array with a linear scan, on purpose. It holds at most 256 entries, /// the common steady state is zero or one, and a scan that exits on the first /// digest byte is faster here than any hashing the lookup would have to do /// first. It is behind `Store.mutex` and never touched from anywhere else. const ActiveSet = struct { const Entry = struct { code: Code, digest: [32]u8, id: i64, }; entries: [Store.mirror_capacity]Entry = undefined, len: u32 = 0, fn find(self: *ActiveSet, code: Code, digest: [32]u8) ?*Entry { for (self.entries[0..self.len]) |*entry| { if (entry.code == code and std.mem.eql(u8, &entry.digest, &digest)) return entry; } return null; } /// False when the mirror is full, which is the caller's signal to count the /// row as untracked instead. fn put(self: *ActiveSet, code: Code, digest: [32]u8, id: i64) bool { if (self.len == self.entries.len) return false; self.entries[self.len] = .{ .code = code, .digest = digest, .id = id }; self.len += 1; return true; } /// Order is not part of the contract, so the last entry fills the hole. fn remove(self: *ActiveSet, entry: *Entry) void { const index = (@intFromPtr(entry) - @intFromPtr(&self.entries[0])) / @sizeOf(Entry); self.len -= 1; self.entries[index] = self.entries[self.len]; } /// Drops every entry of `code` whose key is not in `kept`, mirroring what /// `events_repo.resolveExcept` just did to the table. fn retain(self: *ActiveSet, code: Code, kept: []const []const u8) void { var i: u32 = 0; while (i < self.len) { const entry = &self.entries[i]; if (entry.code != code or keeps(kept, entry.digest)) { i += 1; continue; } self.remove(entry); } } fn keeps(kept: []const []const u8, digest: [32]u8) bool { for (kept) |key| { if (std.mem.eql(u8, &digestOf(key), &digest)) return true; } return false; } }; // --------------------------------------------------------------------------- // tests // --------------------------------------------------------------------------- const migrations = @import("migrations.zig"); const testing = std.testing; test "wire and component are exhaustive, unique and agree with each other" { const all = std.enums.values(Code); try testing.expectEqual(@as(usize, 14), all.len); for (all, 0..) |code, i| { const text = wire(code); // The wire form is `component.name`, and the exhaustive `component` // switch must be the same answer the API's textual prefix match gives. const dot = std.mem.indexOfScalar(u8, text, '.') orelse return error.TestUnexpectedResult; try testing.expectEqualStrings(text[0..dot], component(code)); try testing.expectEqualStrings(component(code), events_repo.componentOf(text)); try testing.expect(dot + 1 < text.len); try testing.expectEqual(code, parseWire(text).?); for (all[i + 1 ..]) |other| { try testing.expect(!std.mem.eql(u8, text, wire(other))); } } try testing.expectEqual(@as(?Code, null), parseWire("nothing.here")); } test "a code's wire form fits the column the mirror reads it back through" { for (std.enums.values(Code)) |code| { try testing.expect(wire(code).len <= events_repo.code_capacity); } } /// A migrated in-memory `config.db` with a `Store` over it. /// /// Built in place rather than returned by value: a `Store` holds a `*db.Db`, so /// a fixture that moved after `Store.init` would leave that pointer behind. const Fixture = struct { threaded: std.Io.Threaded = undefined, io: std.Io = undefined, database: db.Db = undefined, store: Store = undefined, text_buf: [256]u8 = undefined, fn init(self: *Fixture, now_s: i64) !void { self.threaded = .init(testing.allocator, .{}); errdefer self.threaded.deinit(); self.io = self.threaded.io(); self.database = try db.Db.open(":memory:", .{ .mode = .memory }); errdefer self.database.close(); try db.applyPragmas(&self.database, .{}); _ = try migrations.migrate(&self.database); self.store = try Store.init(self.io, &self.database, now_s); } fn deinit(self: *Fixture) void { self.database.close(); self.threaded.deinit(); } fn count(self: *Fixture, sql: []const u8) !i64 { return self.database.queryInt(sql); } fn text(self: *Fixture, sql: []const u8) ![]const u8 { var stmt = try self.database.prepare(sql); defer stmt.deinit(); if (!try stmt.step()) return error.NoRow; const value = stmt.columnText(0); @memcpy(self.text_buf[0..value.len], value); return self.text_buf[0..value.len]; } }; test "an m29 flush-failure episode is resolved once at init and stays listable" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); // The state an m29 database is left in: a live episode under a code that no // producer emits any more, so nothing will ever resolve it. Seeded through // the repository and not through `report`, because the live emitter cannot // name this code — that it cannot is half of what m30 changed. _ = try events_repo.insertActive( &fx.database, 1000, legacy_wire_codes[0], "history", "history", "warning", "Busy", ); try testing.expectEqual( @as(i64, 1), try fx.count("SELECT count(*) FROM operational_events WHERE resolved_at IS NULL"), ); // Reopening is what m30 upgrades on. Ninety days later, so a resolution // stamped with the episode's own `last_seen` would be pruned by this very // call rather than left for an operator to read. const reopened_at = 1000 + Store.resolved_retention_s + 86_400; const upgraded = try Store.init(fx.io, &fx.database, reopened_at); try testing.expectEqual(@as(i64, 1), try fx.count("SELECT count(*) FROM operational_events")); try testing.expectEqual( @as(i64, reopened_at), try fx.count("SELECT resolved_at FROM operational_events"), ); try testing.expectEqualStrings( "upstream_history.write", try fx.text("SELECT code FROM operational_events"), ); // Nothing is open, so the mirror is empty and the SQL slow path is off. try testing.expectEqual(@as(u32, 0), upgraded.active.len); try testing.expectEqual(@as(u32, 0), upgraded.untracked_active_count); // A second start finds nothing left to close, and the sweep is idempotent. const again = try Store.init(fx.io, &fx.database, reopened_at + 60); try testing.expectEqual(@as(u32, 0), again.active.len); try testing.expectEqual( @as(i64, reopened_at), try fx.count("SELECT resolved_at FROM operational_events"), ); } test "a legacy wire code is not something the live emitter can name" { for (legacy_wire_codes) |legacy| { try testing.expectEqual(@as(?Code, null), parseWire(legacy)); for (std.enums.values(Code)) |code| { try testing.expect(!std.mem.eql(u8, legacy, wire(code))); } // The read path still has to answer for it, and does so from the text. const dot = std.mem.indexOfScalar(u8, legacy, '.') orelse return error.TestUnexpectedResult; try testing.expectEqualStrings(legacy[0..dot], events_repo.componentOf(legacy)); try testing.expect(legacy.len <= events_repo.code_capacity); } } test "a failure opens one episode and repeats of it count rather than multiply" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); const store = &fx.store; store.report(fx.io, 1000, .blocklist_refresh, "https://a.example", "A", .warning, "ConnectionTimedOut"); store.report(fx.io, 1060, .blocklist_refresh, "https://a.example", "A", .warning, "ConnectFailed"); store.report(fx.io, 1120, .blocklist_refresh, "https://a.example", "A", .warning, "ConnectFailed"); try testing.expectEqual(@as(i64, 1), try fx.count("SELECT count(*) FROM operational_events")); try testing.expectEqual(@as(i64, 3), try fx.count("SELECT occurrences FROM operational_events")); try testing.expectEqual(@as(i64, 1000), try fx.count("SELECT first_seen FROM operational_events")); try testing.expectEqual(@as(i64, 1120), try fx.count("SELECT last_seen FROM operational_events")); try testing.expect(!store.writeFailed()); try testing.expectEqual(@as(u64, 0), store.writeFailures()); } test "severity rises with the worst failure and never falls back" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); const store = &fx.store; store.report(fx.io, 1000, .query_log_write, "batch", "batch", .warning, "a"); try testing.expectEqualStrings("warning", try severityOf(&fx)); store.report(fx.io, 1010, .query_log_write, "batch", "batch", .@"error", "b"); try testing.expectEqualStrings("error", try severityOf(&fx)); store.report(fx.io, 1020, .query_log_write, "batch", "batch", .warning, "c"); try testing.expectEqualStrings("error", try severityOf(&fx)); } fn severityOf(fx: *Fixture) ![]const u8 { var stmt = try fx.database.prepare("SELECT severity FROM operational_events ORDER BY id DESC LIMIT 1"); defer stmt.deinit(); try testing.expect(try stmt.step()); return @tagName(std.meta.stringToEnum(Severity, stmt.columnText(0)).?); } test "a resolved subject that fails again opens a second episode" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); const store = &fx.store; store.report(fx.io, 1000, .upstream_exchange, "https://a.example", "a.example", .warning, "Timeout"); store.resolve(fx.io, 1100, .upstream_exchange, "https://a.example"); store.report(fx.io, 1200, .upstream_exchange, "https://a.example", "a.example", .warning, "Timeout"); try testing.expectEqual(@as(i64, 2), try fx.count("SELECT count(*) FROM operational_events")); try testing.expectEqual(@as(i64, 1), try fx.count("SELECT count(*) FROM operational_events WHERE resolved_at IS NULL")); try testing.expectEqual(@as(i64, 1100), try fx.count("SELECT resolved_at FROM operational_events WHERE id = 1")); try testing.expectEqual(@as(i64, 1200), try fx.count("SELECT first_seen FROM operational_events WHERE id = 2")); } test "resolving a subject with nothing open executes no SQL at all" { if (!track_statements) return error.SkipZigTest; var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); const store = &fx.store; // The steady state of `pool.recordSuccess`: every successful exchange calls // this, and it must cost a mutex acquire and a lookup. const before = store.statements; for (0..1000) |_| store.resolve(fx.io, 1100, .upstream_exchange, "https://a.example"); try testing.expectEqual(before, store.statements); // With an episode open it does reach the database, once. store.report(fx.io, 1000, .upstream_exchange, "https://a.example", "a.example", .warning, "Timeout"); const after_report = store.statements; store.resolve(fx.io, 1100, .upstream_exchange, "https://a.example"); try testing.expectEqual(after_report + 1, store.statements); // And the mirror is empty again, so the next thousand are free. const after_resolve = store.statements; for (0..1000) |_| store.resolve(fx.io, 1200, .upstream_exchange, "https://a.example"); try testing.expectEqual(after_resolve, store.statements); } test "ensureOpen opens a missing episode and restates an open one without counting it" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); const store = &fx.store; // The reconciliation path: it must be able to reassert a subject that is // still failing without inventing an occurrence no exchange produced. store.ensureOpen(fx.io, 1000, .upstream_exchange, "https://a.example", "a.example", .warning, "Timeout (cause Timeout)"); try testing.expectEqual(@as(i64, 1), try fx.count("SELECT count(*) FROM operational_events WHERE resolved_at IS NULL")); try testing.expectEqual(@as(i64, 1), try fx.count("SELECT occurrences FROM operational_events")); try testing.expectEqual(@as(i64, 1000), try fx.count("SELECT last_seen FROM operational_events")); // The second call is a reconciliation of a card that is already open: the // text and the severity are the reconciler's to state, and the counters // belong to the exchanges that actually failed. store.ensureOpen(fx.io, 1500, .upstream_exchange, "https://a.example", "a.example", .@"error", "SendFailed (cause BrokenPipe)"); try testing.expectEqual(@as(i64, 1), try fx.count("SELECT count(*) FROM operational_events")); try testing.expectEqual(@as(i64, 1), try fx.count("SELECT occurrences FROM operational_events")); try testing.expectEqual(@as(i64, 1000), try fx.count("SELECT first_seen FROM operational_events")); try testing.expectEqual(@as(i64, 1000), try fx.count("SELECT last_seen FROM operational_events")); try testing.expectEqualStrings("error", try fx.text("SELECT severity FROM operational_events")); try testing.expectEqualStrings("SendFailed (cause BrokenPipe)", try fx.text("SELECT detail FROM operational_events")); // And once the episode is resolved it opens a second one, like any other // entry point. store.resolve(fx.io, 1600, .upstream_exchange, "https://a.example"); store.ensureOpen(fx.io, 1700, .upstream_exchange, "https://a.example", "a.example", .warning, "Timeout (cause Timeout)"); try testing.expectEqual(@as(i64, 2), try fx.count("SELECT count(*) FROM operational_events")); try testing.expectEqual(@as(i64, 1700), try fx.count("SELECT first_seen FROM operational_events WHERE id = 2")); } test "a one-shot event inserts already resolved and never enters the mirror" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); const store = &fx.store; store.reportResolved(fx.io, 1000, .query_log_recreated, "one-shot", "corrupt", .warning, "querylog.db.corrupt.1"); try testing.expectEqual(@as(i64, 0), try fx.count("SELECT count(*) FROM operational_events WHERE resolved_at IS NULL")); try testing.expectEqual(@as(u32, 0), store.active.len); // A second boot recreates it again: two rows, no unique-index collision. store.reportResolved(fx.io, 2000, .query_log_recreated, "one-shot", "corrupt", .warning, "querylog.db.corrupt.2"); try testing.expectEqual(@as(i64, 2), try fx.count("SELECT count(*) FROM operational_events")); try testing.expect(!store.writeFailed()); } test "an over-length subject key digests to one stable identity" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); const store = &fx.store; const long = "https://very.long.example/" ++ ("p" ** 400); const other = "https://very.long.example/" ++ ("q" ** 400); store.report(fx.io, 1000, .blocklist_refresh, long, "very.long.example", .warning, "a"); store.report(fx.io, 1010, .blocklist_refresh, long, "very.long.example", .warning, "b"); // A different long url must not join the first one's episode. store.report(fx.io, 1020, .blocklist_refresh, other, "very.long.example", .warning, "c"); try testing.expectEqual(@as(i64, 2), try fx.count("SELECT count(*) FROM operational_events")); try testing.expectEqual(@as(i64, 2), try fx.count("SELECT occurrences FROM operational_events WHERE id = 1")); // The stored key is the digest, at a length the column can hold, and the // same url resolves the same episode. var stmt = try fx.database.prepare("SELECT subject_key FROM operational_events WHERE id = 1"); defer stmt.deinit(); try testing.expect(try stmt.step()); const stored = stmt.columnText(0); try testing.expectEqual(@as(usize, 71), stored.len); try testing.expect(std.mem.startsWith(u8, stored, "sha256:")); // The key never leaves the process, so what is stored may be a digest; the // label is the display identity and is not digested with it. try expectLabel(&fx, 1, "very.long.example"); } /// `columnText` is borrowed until the statement is finalized, so the comparison /// happens here rather than through a returned slice. fn expectLabel(fx: *Fixture, id: i64, expected: []const u8) !void { var stmt = try fx.database.prepare("SELECT subject_label FROM operational_events WHERE id = ?1"); defer stmt.deinit(); try stmt.bindInt(1, id); try testing.expect(try stmt.step()); try testing.expectEqualStrings(expected, stmt.columnText(0)); } test "the same over-length key resolves the episode it opened" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); const store = &fx.store; const long = "https://very.long.example/" ++ ("p" ** 400); store.report(fx.io, 1000, .blocklist_refresh, long, "very.long.example", .warning, "a"); store.resolve(fx.io, 1100, .blocklist_refresh, long); try testing.expectEqual(@as(i64, 0), try fx.count("SELECT count(*) FROM operational_events WHERE resolved_at IS NULL")); } test "a label and a detail longer than their columns are truncated, not refused" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); const store = &fx.store; const long_label = "L" ** (Store.max_subject_label_len + 50); const long_detail = "D" ** (Store.max_detail_len + 50); store.report(fx.io, 1000, .clients_storage, "prune", long_label, .warning, long_detail); var stmt = try fx.database.prepare("SELECT length(subject_label), length(detail) FROM operational_events"); defer stmt.deinit(); try testing.expect(try stmt.step()); try testing.expectEqual(@as(i64, Store.max_subject_label_len), stmt.columnInt(0)); try testing.expectEqual(@as(i64, Store.max_detail_len), stmt.columnInt(1)); try testing.expect(!store.writeFailed()); } test "a failing write latches once, counts every time, and clears on recovery" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); const store = &fx.store; // The whole table gone is what a diagnostics database that has become // unusable looks like from in here. try fx.database.exec("DROP TABLE operational_events;"); for (0..5) |i| { store.report(fx.io, 1000 + @as(i64, @intCast(i)), .disk_space, "data", "data", .warning, "full"); } try testing.expect(store.writeFailed()); try testing.expectEqual(@as(u64, 5), store.writeFailures()); try fx.database.exec(@import("config_schema.zig").operational_events_bridge); store.report(fx.io, 2000, .disk_space, "data", "data", .warning, "full"); // The latch is current state, not a tally: the counter keeps the history. try testing.expect(!store.writeFailed()); try testing.expectEqual(@as(u64, 5), store.writeFailures()); try testing.expectEqual(@as(i64, 1), try fx.count("SELECT count(*) FROM operational_events")); } test "a read neither clears the write latch nor counts as a failed write" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); const store = &fx.store; store.report(fx.io, 1000, .disk_space, "data", "data", .warning, "full"); try fx.database.exec("DROP TABLE operational_events;"); store.report(fx.io, 1010, .disk_space, "data", "data", .warning, "full"); try testing.expect(store.writeFailed()); try testing.expectEqual(@as(u64, 1), store.writeFailures()); // A failed read: no write was attempted, so nothing is counted. try testing.expectEqual(Counts{}, store.activeCounts(fx.io)); try testing.expect(store.writeFailed()); try testing.expectEqual(@as(u64, 1), store.writeFailures()); if (store.selectEvents(fx.io, testing.allocator, .{ .limit = 10 })) |_| { return error.TestExpectedError; } else |_| {} try testing.expectEqual(@as(u64, 1), store.writeFailures()); // A successful read while writes are still broken: the latch stays on // until a write really lands. try fx.database.exec(@import("config_schema.zig").operational_events_bridge); _ = store.activeCounts(fx.io); var arena: std.heap.ArenaAllocator = .init(testing.allocator); defer arena.deinit(); _ = try store.selectEvents(fx.io, arena.allocator(), .{ .limit = 10 }); try testing.expect(store.writeFailed()); store.report(fx.io, 1020, .disk_space, "data", "data", .warning, "full"); try testing.expect(!store.writeFailed()); } test "a refused resolveExcept a caller could not even build is counted and latched" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); const store = &fx.store; store.refuseResolveExcept(fx.io, 1000); try testing.expect(store.writeFailed()); try testing.expectEqual(@as(u64, 1), store.writeFailures()); } test "init fails when the prune it owes cannot run" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); // A resolved row old enough for retention to want it, and a database that // refuses the delete. The mirror still loads, so this is the prune alone. fx.store.reportResolved(fx.io, 1000, .query_log_recreated, "queries", "queries", .warning, "recreated"); try fx.database.exec( \\CREATE TRIGGER no_prune BEFORE DELETE ON operational_events \\BEGIN SELECT RAISE(ABORT, 'no prune'); END; ); if (Store.init(fx.io, &fx.database, 1000 + Store.resolved_retention_s + 1)) |_| { return error.TestExpectedError; } else |_| {} } test "a report whose mirror entry is stale opens the episode rather than losing it" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); const store = &fx.store; store.report(fx.io, 1000, .disk_space, "data", "data", .warning, "full"); // Something outside the store closed the row — the shape a second writer, // or a prune of a row this store thought was open, would leave behind. try fx.database.exec("UPDATE operational_events SET resolved_at = 1050;"); store.report(fx.io, 1100, .disk_space, "data", "data", .@"error", "full"); try testing.expectEqual(@as(i64, 2), try fx.count("SELECT count(*) FROM operational_events")); try testing.expectEqual(@as(i64, 1), try fx.count("SELECT count(*) FROM operational_events WHERE resolved_at IS NULL")); try testing.expect(!store.writeFailed()); } /// Fills the mirror to capacity with episodes of `code`, then opens `overflow` /// more that cannot fit. fn floodActive(fx: *Fixture, store: *Store, overflow: usize) !void { for (0..Store.mirror_capacity + overflow) |i| { var key_buf: [16]u8 = undefined; const key = try std.fmt.bufPrint(&key_buf, "probe{d}", .{i}); store.report(fx.io, 1000, .disk_probe, key, key, .warning, "statvfs"); } } test "an episode past the mirror's capacity is counted, not lost" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); const store = &fx.store; try floodActive(&fx, store, 3); try testing.expectEqual(@as(u32, Store.mirror_capacity), store.active.len); try testing.expectEqual(@as(u32, 3), store.untracked_active_count); try testing.expectEqual( @as(i64, Store.mirror_capacity + 3), try fx.count("SELECT count(*) FROM operational_events WHERE resolved_at IS NULL"), ); } test "a repeat of an untracked episode touches its row rather than colliding" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); const store = &fx.store; try floodActive(&fx, store, 1); const untracked_key = "probe" ++ comptime std.fmt.comptimePrint("{d}", .{Store.mirror_capacity}); // The row is active and outside the mirror, so a second insert would hit // the partial unique index. The probe is what turns it into a touch. store.report(fx.io, 1100, .disk_probe, untracked_key, untracked_key, .@"error", "statvfs again"); try testing.expect(!store.writeFailed()); try testing.expectEqual(@as(u32, 1), store.untracked_active_count); try testing.expectEqual( @as(i64, Store.mirror_capacity + 1), try fx.count("SELECT count(*) FROM operational_events"), ); var stmt = try fx.database.prepare( "SELECT occurrences, severity FROM operational_events WHERE subject_key = ?1", ); defer stmt.deinit(); try stmt.bindText(1, untracked_key); try testing.expect(try stmt.step()); try testing.expectEqual(@as(i64, 2), stmt.columnInt(0)); try testing.expectEqualStrings("error", stmt.columnText(1)); } test "resolving an untracked episode decrements the overflow count exactly once" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); const store = &fx.store; try floodActive(&fx, store, 2); const untracked_key = "probe" ++ comptime std.fmt.comptimePrint("{d}", .{Store.mirror_capacity}); store.resolve(fx.io, 1100, .disk_probe, untracked_key); try testing.expectEqual(@as(u32, 1), store.untracked_active_count); // A second resolve of the same key closed nothing, so it must not count. store.resolve(fx.io, 1200, .disk_probe, untracked_key); try testing.expectEqual(@as(u32, 1), store.untracked_active_count); try testing.expectEqual( @as(i64, Store.mirror_capacity + 1), try fx.count("SELECT count(*) FROM operational_events WHERE resolved_at IS NULL"), ); } test "resolveExcept keeps the named subjects and leaves the mirror and count exact" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); const store = &fx.store; store.report(fx.io, 1000, .listener_start, "doh", "doh", .@"error", "AddressInUse"); store.report(fx.io, 1000, .listener_start, "dot", "dot", .@"error", "AddressInUse"); store.report(fx.io, 1000, .disk_space, "data", "data", .warning, "full"); try testing.expectEqual(@as(u32, 3), store.active.len); store.resolveExcept(fx.io, 2000, .listener_start, &.{"dot"}); try testing.expectEqual(@as(u32, 2), store.active.len); try testing.expectEqual(@as(u32, 0), store.untracked_active_count); try testing.expectEqual(@as(i64, 2), try fx.count("SELECT count(*) FROM operational_events WHERE resolved_at IS NULL")); // The kept episode is the same row, still counting, not a new one. store.report(fx.io, 2100, .listener_start, "dot", "dot", .@"error", "AddressInUse"); try testing.expectEqual(@as(i64, 3), try fx.count("SELECT count(*) FROM operational_events")); try testing.expectEqual( @as(i64, 2), try fx.count("SELECT occurrences FROM operational_events WHERE subject_key = 'dot'"), ); } test "resolveExcept does not reopen an episode resolved in the same second" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); const store = &fx.store; store.report(fx.io, 1000, .blocklist_refresh, "one", "one", .warning, "HttpStatus"); store.report(fx.io, 1000, .blocklist_refresh, "two", "two", .warning, "HttpStatus"); // `blocklist.refresh` uses both halves: a source that succeeds closes its // own episode, and the sweep that follows in the same flush names every // source that still exists — including the one just closed, because it // still exists. Both calls carry the same instant, so a sweep that worked // by stamping `now_s` and reviving would undo the resolve. store.resolve(fx.io, 2000, .blocklist_refresh, "one"); store.resolveExcept(fx.io, 2000, .blocklist_refresh, &.{ "one", "two" }); try testing.expectEqual(@as(i64, 0), try fx.count( "SELECT count(*) FROM operational_events WHERE subject_key = 'one' AND resolved_at IS NULL", )); try testing.expectEqual(@as(i64, 1), try fx.count( "SELECT count(*) FROM operational_events WHERE subject_key = 'two' AND resolved_at IS NULL", )); try testing.expectEqual(@as(u32, 1), store.active.len); try testing.expectEqual(@as(u32, 0), store.untracked_active_count); // And the mark never reaches the table: every resolved row carries the // instant its caller passed. try testing.expectEqual(@as(i64, 2000), try fx.count( "SELECT resolved_at FROM operational_events WHERE subject_key = 'one'", )); } test "resolveExcept canonicalizes an over-length kept key like every other entry point" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); const store = &fx.store; const long = "upstreams[0].url=https://" ++ ("z" ** 400); store.report(fx.io, 1000, .configuration_load, long, "upstreams[0]", .warning, "bad url"); store.report(fx.io, 1000, .configuration_load, "dns.port", "dns.port", .warning, "out of range"); store.resolveExcept(fx.io, 2000, .configuration_load, &.{long}); // The kept key digests to what the report stored, so its episode survived. try testing.expectEqual(@as(i64, 1), try fx.count("SELECT count(*) FROM operational_events WHERE resolved_at IS NULL")); try testing.expectEqual(@as(u32, 1), store.active.len); try testing.expectEqual(@as(u32, 0), store.untracked_active_count); } test "resolveExcept recomputes the overflow count from the table it just committed" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); const store = &fx.store; try floodActive(&fx, store, 4); try testing.expectEqual(@as(u32, 4), store.untracked_active_count); // Nothing of this code is open, so the pass closes nothing — but the count // it returns is of the whole table, which is what keeps the overflow exact. store.resolveExcept(fx.io, 2000, .listener_start, &.{}); try testing.expectEqual(@as(u32, 4), store.untracked_active_count); store.resolveExcept(fx.io, 2100, .disk_probe, &.{}); try testing.expectEqual(@as(u32, 0), store.untracked_active_count); try testing.expectEqual(@as(u32, 0), store.active.len); try testing.expectEqual(@as(i64, 0), try fx.count("SELECT count(*) FROM operational_events WHERE resolved_at IS NULL")); } test "resolveExcept refuses more kept keys than it can canonicalize" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); const store = &fx.store; store.report(fx.io, 1000, .configuration_load, "dns.port", "dns.port", .warning, "out of range"); var keys: [Store.max_kept_keys + 1][]const u8 = undefined; for (&keys, 0..) |*key, i| { key.* = if (i == 0) "dns.port" else "other"; } store.resolveExcept(fx.io, 2000, .configuration_load, &keys); // Refused rather than truncated: the episode it was told to keep is still // open, and the refusal is visible. try testing.expect(store.writeFailed()); try testing.expectEqual(@as(u64, 1), store.writeFailures()); try testing.expectEqual(@as(i64, 1), try fx.count("SELECT count(*) FROM operational_events WHERE resolved_at IS NULL")); } test "a failed resolveExcept changes neither the mirror nor the count" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); const store = &fx.store; store.report(fx.io, 1000, .listener_start, "doh", "doh", .@"error", "AddressInUse"); try fx.database.exec("DROP TABLE operational_events;"); store.resolveExcept(fx.io, 2000, .listener_start, &.{}); try testing.expect(store.writeFailed()); try testing.expectEqual(@as(u32, 1), store.active.len); try testing.expectEqual(@as(u32, 0), store.untracked_active_count); } test "init mirrors what it can and counts the rest as untracked" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); { const store = &fx.store; try floodActive(&fx, store, 5); } // A second store over the same database: the mirror is rebuilt from rows, // not carried over, and the overflow is the difference. var reopened = try Store.init(fx.io, &fx.database, 1000); try testing.expectEqual(@as(u32, Store.mirror_capacity), reopened.active.len); try testing.expectEqual(@as(u32, 5), reopened.untracked_active_count); // And the rebuilt mirror really resolves: a key it loaded closes its row. reopened.resolve(fx.io, 1100, .disk_probe, "probe0"); try testing.expectEqual( @as(i64, Store.mirror_capacity + 4), try fx.count("SELECT count(*) FROM operational_events WHERE resolved_at IS NULL"), ); } test "init leaves a row whose code this build does not know active and untracked" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); try fx.database.exec( \\INSERT INTO operational_events \\ (code, subject_key, subject_label, severity, first_seen, last_seen, occurrences) \\VALUES ('from.the.future', 'x', 'x', 'warning', 100, 100, 1); ); const reopened = try Store.init(fx.io, &fx.database, 1000); try testing.expectEqual(@as(u32, 0), reopened.active.len); try testing.expectEqual(@as(u32, 1), reopened.untracked_active_count); } test "init prunes the resolved rows retention no longer covers" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); { const store = &fx.store; store.report(fx.io, 1000, .disk_space, "data", "data", .warning, "full"); store.resolve(fx.io, 1100, .disk_space, "data"); store.report(fx.io, 1200, .clients_storage, "prune", "prune", .warning, "Busy"); } try testing.expectEqual(@as(i64, 2), try fx.count("SELECT count(*) FROM operational_events")); // Long past the resolved row's retention window, and the active one is // never a candidate for it. const reopened = try Store.init(fx.io, &fx.database, 1100 + Store.resolved_retention_s + 1); try testing.expectEqual(@as(i64, 1), try fx.count("SELECT count(*) FROM operational_events")); try testing.expectEqual(@as(u32, 1), reopened.active.len); } test "prune keeps active episodes and drops resolved ones past the window" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); const store = &fx.store; store.report(fx.io, 1000, .disk_space, "data", "data", .warning, "full"); store.resolve(fx.io, 1100, .disk_space, "data"); store.report(fx.io, 1200, .clients_storage, "prune", "prune", .warning, "Busy"); store.prune(fx.io, 1300); try testing.expectEqual(@as(i64, 2), try fx.count("SELECT count(*) FROM operational_events")); store.prune(fx.io, 1100 + Store.resolved_retention_s + 1); try testing.expectEqual(@as(i64, 1), try fx.count("SELECT count(*) FROM operational_events")); try testing.expectEqual(@as(i64, 1), try fx.count("SELECT count(*) FROM operational_events WHERE resolved_at IS NULL")); } test "purging one event takes a resolved episode and refuses the open one" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); const store = &fx.store; store.report(fx.io, 1000, .disk_space, "data", "data", .warning, "full"); store.report(fx.io, 1000, .clients_storage, "prune", "prune", .warning, "Busy"); store.resolve(fx.io, 1100, .clients_storage, "prune"); try testing.expectEqual(PurgeOutcome.active, try store.purge(fx.io, 1)); try testing.expectEqual(PurgeOutcome.deleted, try store.purge(fx.io, 2)); try testing.expectEqual(PurgeOutcome.absent, try store.purge(fx.io, 2)); try testing.expectEqual(PurgeOutcome.absent, try store.purge(fx.io, 9999)); try testing.expectEqual(@as(i64, 1), try fx.count("SELECT count(*) FROM operational_events")); try testing.expect(!store.writeFailed()); // The open episode the purge refused is still the one the mirror points at: // a later success closes that row rather than opening a second one. store.resolve(fx.io, 1200, .disk_space, "data"); try testing.expectEqual(@as(i64, 0), try fx.count("SELECT count(*) FROM operational_events WHERE resolved_at IS NULL")); try testing.expectEqual(@as(u32, 0), store.active.len); } test "purgeAll leaves every active episode, and the mirror still matches the table" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); const store = &fx.store; // Two open episodes, one of them past the mirror, plus resolved history of // both kinds: a closed episode and a one-shot row. try floodActive(&fx, store, 1); store.report(fx.io, 1000, .clients_storage, "prune", "prune", .warning, "Busy"); store.resolve(fx.io, 1100, .clients_storage, "prune"); store.reportResolved(fx.io, 1100, .query_log_recreated, "one-shot", "corrupt", .warning, "aside"); const mirrored = store.active.len; const untracked = store.untracked_active_count; try testing.expectEqual(@as(i64, 2), try store.purgeAll(fx.io)); // Neither half of the overflow accounting moved, and both still describe // the table: nothing that could have been in them was a candidate. try testing.expectEqual(mirrored, store.active.len); try testing.expectEqual(untracked, store.untracked_active_count); try testing.expectEqual( @as(i64, @as(i64, store.active.len) + untracked), try fx.count("SELECT count(*) FROM operational_events WHERE resolved_at IS NULL"), ); try testing.expectEqual(@as(i64, 0), try fx.count("SELECT count(*) FROM operational_events WHERE resolved_at IS NOT NULL")); // The untracked episode still resolves through the slow path, which is what // proves the count survived the purge. const untracked_key = "probe" ++ comptime std.fmt.comptimePrint("{d}", .{Store.mirror_capacity}); store.resolve(fx.io, 1200, .disk_probe, untracked_key); try testing.expectEqual(@as(u32, 0), store.untracked_active_count); // And the episode it just closed is what the next purge takes. try testing.expectEqual(@as(i64, 1), try store.purgeAll(fx.io)); } test "a failed purge reaches the caller and latches like any other write" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); const store = &fx.store; try fx.database.exec("DROP TABLE operational_events;"); // Unlike an emitter's report, a request's purge must not be swallowed: the // handler owes the operator a 500 rather than a silent no-op. try testing.expectError(error.Unexpected, store.purge(fx.io, 1)); try testing.expectError(error.Unexpected, store.purgeAll(fx.io)); try testing.expect(store.writeFailed()); try testing.expectEqual(@as(u64, 2), store.writeFailures()); try fx.database.exec(@import("config_schema.zig").operational_events_bridge); _ = try store.purgeAll(fx.io); try testing.expect(!store.writeFailed()); } test "activeCounts and a page are read through the store's own lock" { var fx: Fixture = .{}; try fx.init(1000); defer fx.deinit(); const store = &fx.store; store.report(fx.io, 1000, .disk_space, "data", "data", .warning, "full"); store.report(fx.io, 1000, .listener_start, "doh", "doh", .@"error", "AddressInUse"); store.report(fx.io, 1000, .upstream_exchange, "https://a.example", "a.example", .warning, "Timeout"); store.resolve(fx.io, 1100, .upstream_exchange, "https://a.example"); try testing.expectEqual(Counts{ .warnings = 1, .errors = 1 }, store.activeCounts(fx.io)); var arena: std.heap.ArenaAllocator = .init(testing.allocator); defer arena.deinit(); const page = try store.selectEvents(fx.io, arena.allocator(), .{ .limit = 100 }); try testing.expectEqual(@as(usize, 3), page.events.len); try testing.expectEqual(@as(?i64, null), page.next_before); try testing.expectEqual(Counts{ .warnings = 1, .errors = 1 }, page.active); const first = try store.selectEvents(fx.io, arena.allocator(), .{ .limit = 2 }); try testing.expectEqual(@as(usize, 2), first.events.len); try testing.expectEqual(first.events[1].id, first.next_before.?); const one = (try store.selectOne(fx.io, arena.allocator(), first.events[0].id)).?; try testing.expectEqualStrings(first.events[0].code, one.code); try testing.expect((try store.selectOne(fx.io, arena.allocator(), 9999)) == null); } test "canonicalKey is verbatim up to the cap and a stable digest past it" { var buf: [Store.max_subject_key_len]u8 = undefined; try testing.expectEqualStrings("data", canonicalKey("data", &buf)); const at_cap = "k" ** Store.max_subject_key_len; try testing.expectEqualStrings(at_cap, canonicalKey(at_cap, &buf)); const over = "k" ** (Store.max_subject_key_len + 1); var other_buf: [Store.max_subject_key_len]u8 = undefined; const digest = canonicalKey(over, &buf); try testing.expectEqual(@as(usize, 71), digest.len); try testing.expect(std.mem.startsWith(u8, digest, "sha256:")); // Deterministic, and distinct inputs stay distinct. try testing.expectEqualStrings(digest, canonicalKey(over, &other_buf)); try testing.expect(!std.mem.eql(u8, digest, canonicalKey(over ++ "k", &other_buf))); }