Compare commits
4 Commits
| Author | SHA1 | Date | |
|---|---|---|---|
| 22544ecf63 | |||
| ba5b4b1f4e | |||
| 51b160bfc9 | |||
| e2d5105da2 |
@@ -192,11 +192,78 @@ describe("ButtonLightController truth table", () => {
|
||||
// First write (initial off) throws — must be swallowed.
|
||||
expect(() => ctl.start()).not.toThrow();
|
||||
await flush();
|
||||
// Subsequent writes work; driving to solid still converges to ON.
|
||||
// The failure arms a backoff (1s) rather than retrying inline; desired-state
|
||||
// changes during the window just update the target the retry will assert.
|
||||
lane(true);
|
||||
radar(true);
|
||||
await flush();
|
||||
expect(ctl.confirmedOf(CONTROLLER)).toBeNull(); // still backing off
|
||||
await vi.advanceTimersByTimeAsync(1000); // retry fires; aux is healthy again
|
||||
expect(ctl.confirmedOf(CONTROLLER)).toBe(true); // converged to solid ON
|
||||
ctl.stop();
|
||||
});
|
||||
|
||||
it("an unreachable controller backs off (1s→30s), not a hot retry loop", async () => {
|
||||
let attempts = 0;
|
||||
const aux: AuxOutputDevice = {
|
||||
async setAux() {
|
||||
attempts += 1;
|
||||
throw new Error("send ENETUNREACH 10.0.10.5:60000");
|
||||
},
|
||||
};
|
||||
const errors: string[] = [];
|
||||
const logger = silentLogger();
|
||||
(logger as { error: (msg: string) => void }).error = (msg) => errors.push(msg);
|
||||
const ctl = new ButtonLightController(db, logger, () => aux);
|
||||
ctl.start(); // initial OFF write → attempt 1 fails at t=0
|
||||
await flush();
|
||||
expect(attempts).toBe(1); // the old code hot-looped here
|
||||
|
||||
// Failures at t≈0,1,3,7,15,31 (doubling, capped 30s) → 6 attempts in the first
|
||||
// minute instead of thousands.
|
||||
await vi.advanceTimersByTimeAsync(60_000);
|
||||
expect(attempts).toBeGreaterThanOrEqual(5);
|
||||
expect(attempts).toBeLessThanOrEqual(7);
|
||||
|
||||
// Only the FIRST failure was logged so far; the next log is a ≥60s summary.
|
||||
expect(errors).toHaveLength(1);
|
||||
await vi.advanceTimersByTimeAsync(35_000); // t≈95s → the t=61s attempt logged a summary
|
||||
expect(errors.length).toBe(2);
|
||||
expect(errors[1]).toContain("still failing");
|
||||
ctl.stop();
|
||||
});
|
||||
|
||||
it("logs a single recovery line and resets the backoff after success", async () => {
|
||||
let failing = true;
|
||||
let attempts = 0;
|
||||
const aux: AuxOutputDevice = {
|
||||
async setAux() {
|
||||
attempts += 1;
|
||||
if (failing) throw new Error("send ENETUNREACH 10.0.10.5:60000");
|
||||
},
|
||||
};
|
||||
const infos: string[] = [];
|
||||
const logger = silentLogger();
|
||||
(logger as { info: (msg: string) => void }).info = (msg) => infos.push(msg);
|
||||
const ctl = new ButtonLightController(db, logger, () => aux);
|
||||
ctl.start();
|
||||
await flush();
|
||||
await vi.advanceTimersByTimeAsync(3_000); // attempts at t=0,1,3 all fail
|
||||
const failed = attempts;
|
||||
expect(failed).toBeGreaterThanOrEqual(3);
|
||||
|
||||
failing = false; // controller reachable again
|
||||
await vi.advanceTimersByTimeAsync(8_000); // next armed retry succeeds
|
||||
expect(ctl.confirmedOf(CONTROLLER)).toBe(false); // OFF asserted on the device
|
||||
expect(infos.filter((m) => m.includes("recovered"))).toHaveLength(1);
|
||||
|
||||
// Backoff reset: a fresh state change sends immediately (no lingering retryAt).
|
||||
const before = attempts;
|
||||
lane(true);
|
||||
radar(true);
|
||||
await flush();
|
||||
expect(ctl.confirmedOf(CONTROLLER)).toBe(true);
|
||||
expect(attempts).toBe(before + 1);
|
||||
ctl.stop();
|
||||
});
|
||||
|
||||
|
||||
@@ -21,6 +21,14 @@ type LightState = "off" | "solid" | "blink";
|
||||
|
||||
const DEFAULT_BLINK_MS = 500;
|
||||
|
||||
// Failed-send retry backoff: 1s doubling to 30s, reset on success. Without this an
|
||||
// unreachable controller (ENETUNREACH) became a hot loop — the failure re-pump retried
|
||||
// instantly, thousands of sends + error lines per minute (field incident 2026-07-07).
|
||||
const RETRY_BASE_MS = 1_000;
|
||||
const RETRY_MAX_MS = 30_000;
|
||||
/** After the first failure of a streak, log at most one summary line per this window. */
|
||||
const FAIL_LOG_EVERY_MS = 60_000;
|
||||
|
||||
/** Per-lamp live state for the alert rule (one per radarAlert relay). */
|
||||
interface LampState {
|
||||
/** The controller this lamp lives on (its deviceId) — for resolving the aux adapter. */
|
||||
@@ -44,6 +52,16 @@ interface LampState {
|
||||
/** True while a send is in flight for this lamp — serializes UDP so on/off can't
|
||||
* overlap or reorder (UDP is unordered; concurrent toggles left the relay stuck). */
|
||||
sending: boolean;
|
||||
/** Consecutive failed sends (0 = healthy). Drives the backoff delay + log summaries. */
|
||||
failCount: number;
|
||||
/** Epoch ms before which #pump must not send (0 = no backoff). The armed retry
|
||||
* timer re-pumps when it elapses; desired-state changes in between just update
|
||||
* `desiredOn` and are picked up by that same retry. */
|
||||
retryAt: number;
|
||||
/** The armed backoff retry, if any. */
|
||||
retryTimer: ReturnType<typeof setTimeout> | null;
|
||||
/** Epoch ms of the last failure line we actually logged (rate-limits the flood). */
|
||||
lastFailLogAt: number;
|
||||
}
|
||||
|
||||
/** Resolves a controller's live aux-output adapter. The default goes through the
|
||||
@@ -111,6 +129,10 @@ export class ButtonLightController {
|
||||
desiredOn: false,
|
||||
confirmedOn: null,
|
||||
sending: false,
|
||||
failCount: 0,
|
||||
retryAt: 0,
|
||||
retryTimer: null,
|
||||
lastFailLogAt: 0,
|
||||
});
|
||||
}
|
||||
}
|
||||
@@ -118,10 +140,7 @@ export class ButtonLightController {
|
||||
// Drop lamps whose controller no longer declares one (or was disabled/removed).
|
||||
for (const [key, lamp] of this.#lamps) {
|
||||
if (seen.has(key)) continue;
|
||||
if (lamp.blink) {
|
||||
clearInterval(lamp.blink);
|
||||
lamp.blink = null;
|
||||
}
|
||||
this.#disarm(lamp);
|
||||
this.#finalOff(lamp); // best-effort fail-OFF before forgetting it
|
||||
this.#lamps.delete(key);
|
||||
}
|
||||
@@ -207,10 +226,17 @@ export class ButtonLightController {
|
||||
* time. Because UDP is unordered, concurrent on/off sends previously raced and left
|
||||
* the relay stuck on a stale packet. Here a single in-flight send is guaranteed
|
||||
* (`sending` guard); when it resolves, if the desired state moved on we send again —
|
||||
* so the LAST desired state is always the one finally asserted on the device. */
|
||||
* so the LAST desired state is always the one finally asserted on the device.
|
||||
*
|
||||
* Failures back off (1s → 30s, reset on success) instead of retrying inline: an
|
||||
* unreachable controller rejects instantly, and an immediate re-pump was a hot loop.
|
||||
* During backoff `desiredOn` keeps tracking the truth table; the armed retry timer
|
||||
* converges to whatever it says when it fires. Only the FIRST failure of a streak is
|
||||
* logged, then one summary per minute, and an info line on recovery. */
|
||||
#pump(lamp: LampState): void {
|
||||
if (lamp.sending) return; // a send is already in flight; it'll re-check on completion
|
||||
if (lamp.confirmedOn === lamp.desiredOn) return; // already there — no redundant UDP
|
||||
if (Date.now() < lamp.retryAt) return; // backing off — the retry timer will re-pump
|
||||
const aux = this.#resolveAux(lamp.controllerId);
|
||||
if (!aux) return;
|
||||
const target = lamp.desiredOn;
|
||||
@@ -219,15 +245,42 @@ export class ButtonLightController {
|
||||
.setAux(lamp.spec.relay, target)
|
||||
.then(() => {
|
||||
lamp.confirmedOn = target;
|
||||
if (lamp.failCount > 0) {
|
||||
this.#logger.info(
|
||||
`button-light setAux recovered (${lamp.controllerId} R${lamp.spec.relay}) after ${lamp.failCount} failed attempts`,
|
||||
);
|
||||
}
|
||||
lamp.failCount = 0;
|
||||
lamp.retryAt = 0;
|
||||
lamp.lastFailLogAt = 0;
|
||||
})
|
||||
.catch((err: unknown) => {
|
||||
// Leave confirmedOn unchanged so the next pump retries this state. Never escalates.
|
||||
this.#logger.error(`button-light setAux failed (${lamp.controllerId} R${lamp.spec.relay}): ${(err as Error).message}`);
|
||||
// Leave confirmedOn unchanged so the armed retry re-asserts the (then-current)
|
||||
// desired state. Never escalates — a dead lamp is "no hint", never a fault.
|
||||
lamp.failCount += 1;
|
||||
const delay = Math.min(RETRY_BASE_MS * 2 ** (lamp.failCount - 1), RETRY_MAX_MS);
|
||||
lamp.retryAt = Date.now() + delay;
|
||||
const now = Date.now();
|
||||
if (lamp.failCount === 1 || now - lamp.lastFailLogAt >= FAIL_LOG_EVERY_MS) {
|
||||
lamp.lastFailLogAt = now;
|
||||
const streak =
|
||||
lamp.failCount > 1 ? ` — still failing (attempt ${lamp.failCount}, retrying ≤${RETRY_MAX_MS / 1000}s)` : "";
|
||||
this.#logger.error(
|
||||
`button-light setAux failed (${lamp.controllerId} R${lamp.spec.relay}): ${(err as Error).message}${streak}`,
|
||||
);
|
||||
}
|
||||
if (lamp.retryTimer) clearTimeout(lamp.retryTimer);
|
||||
lamp.retryTimer = setTimeout(() => {
|
||||
lamp.retryTimer = null;
|
||||
this.#pump(lamp);
|
||||
}, delay);
|
||||
lamp.retryTimer.unref?.();
|
||||
})
|
||||
.finally(() => {
|
||||
lamp.sending = false;
|
||||
// Desired state may have changed (or the send failed) while we were busy —
|
||||
// re-pump to converge. This is what makes the final state authoritative.
|
||||
// Desired state may have changed while we were busy — re-pump to converge (the
|
||||
// backoff gate above makes this a no-op right after a failure). This is what
|
||||
// makes the final state authoritative.
|
||||
if (lamp.confirmedOn !== lamp.desiredOn) this.#pump(lamp);
|
||||
});
|
||||
}
|
||||
@@ -261,20 +314,31 @@ export class ButtonLightController {
|
||||
this.#unsubInput = null;
|
||||
this.#unsubLane = null;
|
||||
for (const lamp of this.#lamps.values()) {
|
||||
if (lamp.blink) {
|
||||
clearInterval(lamp.blink);
|
||||
lamp.blink = null;
|
||||
}
|
||||
this.#disarm(lamp);
|
||||
// Best-effort fail-OFF on shutdown.
|
||||
this.#finalOff(lamp);
|
||||
}
|
||||
}
|
||||
|
||||
/** Stop a lamp's timers (blink + backoff retry) without touching the device. */
|
||||
#disarm(lamp: LampState): void {
|
||||
if (lamp.blink) {
|
||||
clearInterval(lamp.blink);
|
||||
lamp.blink = null;
|
||||
}
|
||||
if (lamp.retryTimer) {
|
||||
clearTimeout(lamp.retryTimer);
|
||||
lamp.retryTimer = null;
|
||||
}
|
||||
}
|
||||
|
||||
/** Drive a lamp OFF as a one-shot (used when dropping/stopping a lamp): set desired
|
||||
* OFF and pump. The serialized worker still applies, so this can't collide with an
|
||||
* in-flight send — it converges to OFF. */
|
||||
* in-flight send — it converges to OFF. Any backoff is waived so the last-gasp OFF
|
||||
* gets one immediate try (a lamp mid-backoff may just have recovered). */
|
||||
#finalOff(lamp: LampState): void {
|
||||
lamp.desiredOn = false;
|
||||
lamp.retryAt = 0;
|
||||
this.#pump(lamp);
|
||||
}
|
||||
|
||||
|
||||
@@ -1,4 +1,4 @@
|
||||
import { beforeEach, describe, expect, it } from "vitest";
|
||||
import { afterEach, beforeEach, describe, expect, it, vi } from "vitest";
|
||||
import { appLogs, type Db } from "@parking/db";
|
||||
import { createTestDb } from "@parking/db/testing";
|
||||
import { LogService, pinoDbStream } from "./log-service.js";
|
||||
@@ -52,3 +52,65 @@ describe("pinoDbStream level encodings", () => {
|
||||
expect(teed).toHaveLength(2);
|
||||
});
|
||||
});
|
||||
|
||||
// Storm coalescing: a line identical to the LAST persisted row (level+source+message+
|
||||
// path), arriving within 5 min of its previous occurrence, UPDATES that row (bumping
|
||||
// context._repeat) instead of inserting — one screaming device can't evict unrelated
|
||||
// history. The row's createdAt tracks the LATEST occurrence; the first is preserved in
|
||||
// context._firstAt.
|
||||
describe("storm coalescing", () => {
|
||||
afterEach(() => {
|
||||
vi.useRealTimers();
|
||||
});
|
||||
|
||||
it("folds a burst of identical error lines into ONE row with a repeat counter", () => {
|
||||
for (let i = 0; i < 200; i++) {
|
||||
stream.write(`{"level":"error","msg":"button-light setAux failed (ctl R3): send ENETUNREACH"}\n`);
|
||||
}
|
||||
const all = rows();
|
||||
expect(all).toHaveLength(1);
|
||||
expect(all[0].context).toMatchObject({ _repeat: 200 });
|
||||
expect(teed).toHaveLength(200); // stdout still gets every line
|
||||
});
|
||||
|
||||
it("keeps first-occurrence time in _firstAt while createdAt tracks the latest", () => {
|
||||
vi.useFakeTimers();
|
||||
vi.setSystemTime(new Date("2026-07-08T10:00:00.000Z"));
|
||||
stream.write(`{"level":"warn","msg":"same"}\n`);
|
||||
vi.setSystemTime(new Date("2026-07-08T10:02:00.000Z"));
|
||||
stream.write(`{"level":"warn","msg":"same"}\n`);
|
||||
const [row] = rows();
|
||||
expect(row.createdAt).toBe("2026-07-08T10:02:00.000Z");
|
||||
expect(row.context).toMatchObject({ _repeat: 2, _firstAt: "2026-07-08T10:00:00.000Z" });
|
||||
});
|
||||
|
||||
it("a different message (or level) breaks the run — separate rows", () => {
|
||||
stream.write(`{"level":"error","msg":"boom A"}\n`);
|
||||
stream.write(`{"level":"error","msg":"boom A"}\n`);
|
||||
stream.write(`{"level":"error","msg":"boom B"}\n`);
|
||||
stream.write(`{"level":"warn","msg":"boom B"}\n`);
|
||||
expect(rows()).toHaveLength(3);
|
||||
});
|
||||
|
||||
it("an occurrence past the 5-minute window starts a fresh row", () => {
|
||||
vi.useFakeTimers();
|
||||
vi.setSystemTime(new Date("2026-07-08T10:00:00.000Z"));
|
||||
stream.write(`{"level":"error","msg":"slow leak"}\n`);
|
||||
vi.setSystemTime(new Date("2026-07-08T10:06:00.000Z"));
|
||||
stream.write(`{"level":"error","msg":"slow leak"}\n`);
|
||||
expect(rows()).toHaveLength(2);
|
||||
});
|
||||
|
||||
it("a CONTINUOUS storm stays one row past the window (each hit refreshes it)", () => {
|
||||
vi.useFakeTimers();
|
||||
let t = new Date("2026-07-08T10:00:00.000Z").getTime();
|
||||
for (let i = 0; i < 10; i++) {
|
||||
vi.setSystemTime(new Date(t));
|
||||
stream.write(`{"level":"error","msg":"storm"}\n`);
|
||||
t += 240_000; // 4 min apart — each inside the window of the PREVIOUS hit
|
||||
}
|
||||
const all = rows();
|
||||
expect(all).toHaveLength(1);
|
||||
expect(all[0].context).toMatchObject({ _repeat: 10 });
|
||||
});
|
||||
});
|
||||
|
||||
@@ -25,6 +25,14 @@ const MAX_MESSAGE = 4_000;
|
||||
const MAX_STACK = 16_000;
|
||||
const MAX_CONTEXT_JSON = 16_000;
|
||||
|
||||
/** Storm coalescing: a line identical to the LAST persisted one (level+source+message+
|
||||
* path) within this window of its previous occurrence UPDATES that row (bumping a
|
||||
* `_repeat` counter in its context) instead of inserting a new one. A continuous storm
|
||||
* keeps refreshing the window, so it stays ONE row however long it rages — repeated
|
||||
* errors can't evict unrelated history or grind the appliance disk (field incident
|
||||
* 2026-07-07: one unreachable controller ≈ hundreds of identical rows/minute). */
|
||||
const COALESCE_WINDOW_MS = 300_000;
|
||||
|
||||
export interface LogRetention {
|
||||
/** Delete logs older than this many days. */
|
||||
readonly maxAgeDays: number;
|
||||
@@ -62,6 +70,16 @@ export class LogService {
|
||||
readonly #retention: LogRetention;
|
||||
/** Reentrancy guard: never let persisting a log itself emit a persisted log. */
|
||||
#writing = false;
|
||||
/** The last persisted row, for storm coalescing (in-memory only; a restart just
|
||||
* starts a fresh row — best-effort, like everything in this sink). */
|
||||
#last: {
|
||||
id: string;
|
||||
key: string;
|
||||
count: number;
|
||||
firstAt: string;
|
||||
lastAtMs: number;
|
||||
baseContext: Record<string, unknown> | null;
|
||||
} | null = null;
|
||||
|
||||
constructor(db: Db, retention: LogRetention = DEFAULT_RETENTION) {
|
||||
this.#db = db;
|
||||
@@ -85,22 +103,53 @@ export class LogService {
|
||||
if (this.#writing) return;
|
||||
this.#writing = true;
|
||||
try {
|
||||
const createdAt = row.createdAt ?? new Date().toISOString();
|
||||
const message = clamp(row.message, MAX_MESSAGE) ?? "";
|
||||
const path = clamp(row.path, 512);
|
||||
const key = `${row.level}|${row.source}|${message}|${path ?? ""}`;
|
||||
const nowMs = Date.now();
|
||||
|
||||
// Storm coalescing: identical to the last persisted row, within the window →
|
||||
// bump that row instead of inserting. createdAt moves to the LATEST occurrence
|
||||
// (keeps the storm visible at the top of the newest-first viewer); the first
|
||||
// occurrence's time is preserved in context._firstAt.
|
||||
const last = this.#last;
|
||||
if (last && last.key === key && nowMs - last.lastAtMs <= COALESCE_WINDOW_MS) {
|
||||
const res = this.#db
|
||||
.update(appLogs)
|
||||
.set({
|
||||
context: { ...(last.baseContext ?? {}), _repeat: last.count + 1, _firstAt: last.firstAt },
|
||||
createdAt,
|
||||
})
|
||||
.where(eq(appLogs.id, last.id))
|
||||
.run();
|
||||
if ((res.changes ?? 0) > 0) {
|
||||
last.count += 1;
|
||||
last.lastAtMs = nowMs;
|
||||
return;
|
||||
}
|
||||
// The row was pruned out from under us — fall through to a fresh insert.
|
||||
}
|
||||
|
||||
const id = randomUUID();
|
||||
const baseContext = safeContext(row.context);
|
||||
this.#db
|
||||
.insert(appLogs)
|
||||
.values({
|
||||
id: randomUUID(),
|
||||
id,
|
||||
level: row.level,
|
||||
source: row.source,
|
||||
message: clamp(row.message, MAX_MESSAGE) ?? "",
|
||||
context: safeContext(row.context),
|
||||
message,
|
||||
context: baseContext,
|
||||
httpStatus: row.httpStatus ?? null,
|
||||
path: clamp(row.path, 512),
|
||||
path,
|
||||
stack: clamp(row.stack, MAX_STACK),
|
||||
userId: row.userId ?? null,
|
||||
userAgent: clamp(row.userAgent, 512),
|
||||
createdAt: row.createdAt ?? new Date().toISOString(),
|
||||
createdAt,
|
||||
})
|
||||
.run();
|
||||
this.#last = { id, key, count: 1, firstAt: createdAt, lastAtMs: nowMs, baseContext };
|
||||
} catch {
|
||||
// Swallow — diagnostics must never take down the path they observe. (Can't log
|
||||
// it; that's the recursion we're guarding against.)
|
||||
|
||||
@@ -25,6 +25,10 @@ function LogRow({ log }: { log: AppLogRecord }) {
|
||||
const { t } = useTranslation();
|
||||
const [open, setOpen] = useState(false);
|
||||
const hasDetail = (log.context && Object.keys(log.context).length > 0) || log.stack;
|
||||
// Storm-coalesced row: the server folds repeated identical lines into one row and
|
||||
// counts them in context._repeat (first occurrence kept in _firstAt).
|
||||
const repeat = typeof log.context?._repeat === "number" ? (log.context?._repeat as number) : null;
|
||||
const firstAt = typeof log.context?._firstAt === "string" ? (log.context?._firstAt as string) : null;
|
||||
|
||||
return (
|
||||
<div className={`border-b border-term-border/50 ${log.level === "error" || log.level === "fatal" ? "bg-term-red/5" : ""}`}>
|
||||
@@ -38,7 +42,20 @@ function LogRow({ log }: { log: AppLogRecord }) {
|
||||
<span className="text-term-muted tabular-nums">{formatRelativeDateTime(log.createdAt, t)}</span>
|
||||
<span className={`font-semibold uppercase ${LEVEL_COLOR[log.level]}`}>{log.level}</span>
|
||||
<span className="text-term-muted">{t(log.source === "frontend" ? "logs.frontend" : "logs.backend")}</span>
|
||||
<span className="truncate text-term-text">{log.message}</span>
|
||||
<span className="truncate text-term-text">
|
||||
{repeat != null && repeat > 1 && (
|
||||
<span
|
||||
className="mr-1.5 rounded-term border border-term-amber/50 px-1 text-[0.625rem] font-semibold text-term-amber"
|
||||
title={t("logs.repeated", {
|
||||
count: repeat,
|
||||
firstAt: firstAt ? formatRelativeDateTime(firstAt, t) : "—",
|
||||
})}
|
||||
>
|
||||
×{repeat}
|
||||
</span>
|
||||
)}
|
||||
{log.message}
|
||||
</span>
|
||||
<span className="text-term-muted tabular-nums">{log.httpStatus ?? ""}</span>
|
||||
</button>
|
||||
{open && hasDetail && (
|
||||
|
||||
@@ -947,6 +947,7 @@ export const en: Catalog = {
|
||||
status: "Status",
|
||||
path: "Path",
|
||||
empty: "No logs.",
|
||||
repeated: "Repeated {{count}} times (first at {{firstAt}})",
|
||||
},
|
||||
backup: {
|
||||
title: "Backup",
|
||||
|
||||
@@ -963,6 +963,7 @@ export const sq = {
|
||||
status: "Statusi",
|
||||
path: "Rruga",
|
||||
empty: "Asnjë regjistër.",
|
||||
repeated: "Përsëritur {{count}} herë (hera e parë {{firstAt}})",
|
||||
},
|
||||
backup: {
|
||||
title: "Kopje rezervë",
|
||||
|
||||
@@ -17,9 +17,17 @@
|
||||
// their credentials/plates, blocklist. KEEPS users, devices, config,
|
||||
// tariffs, subscription PLANS.
|
||||
// --config site_config, devices, setup_state (re-runs first-run setup),
|
||||
// tariffs + tariff_versions, subscription_plans.
|
||||
// tariffs + tariff_versions + tariff_drafts, subscription_plans.
|
||||
// --users users, roles, role_permissions, auth sessions. (After this or --all,
|
||||
// re-seed an admin: apps/server/scripts/seed-admin.mjs.)
|
||||
// --diagnostics app_logs (the unsigned diagnostic store behind the /setup/logs
|
||||
// viewer). Separate from --financial: logs are evidence about the BOX,
|
||||
// not the traffic — wipe them only when handing over a blank slate.
|
||||
//
|
||||
// DRIFT GUARD: before doing anything, the script compares the union of the categories
|
||||
// above against the tables actually present in the DB and REFUSES if any table is
|
||||
// uncategorized — so a new table can't silently survive resets (app_logs and
|
||||
// tariff_drafts did exactly that until 2026-07-08).
|
||||
//
|
||||
// Safety gates (BOTH required):
|
||||
// 1. env RESET_ALLOWED=1 — a real booth never sets this.
|
||||
@@ -44,10 +52,39 @@ const CATEGORIES = {
|
||||
"subscriptions",
|
||||
"blocklist",
|
||||
],
|
||||
config: ["site_config", "devices", "setup_state", "tariff_versions", "tariffs", "subscription_plans"],
|
||||
config: [
|
||||
"site_config",
|
||||
"devices",
|
||||
"setup_state",
|
||||
"tariff_drafts",
|
||||
"tariff_versions",
|
||||
"tariffs",
|
||||
"subscription_plans",
|
||||
],
|
||||
users: ["sessions", "role_permissions", "users", "roles"],
|
||||
diagnostics: ["app_logs"],
|
||||
};
|
||||
|
||||
/** Every user table in the DB must belong to a category above (internal bookkeeping
|
||||
* like sqlite_* and drizzle's __* migration table excepted). Dies listing offenders —
|
||||
* the fix is a one-line addition to CATEGORIES, decided deliberately, not by omission. */
|
||||
function assertNoUncategorizedTables(sqlite) {
|
||||
const known = new Set(Object.values(CATEGORIES).flat());
|
||||
const actual = sqlite
|
||||
.prepare(`SELECT name FROM sqlite_master WHERE type = 'table'`)
|
||||
.all()
|
||||
.map((r) => r.name)
|
||||
.filter((n) => !n.startsWith("sqlite_") && !n.startsWith("__"));
|
||||
const uncategorized = actual.filter((n) => !known.has(n));
|
||||
if (uncategorized.length > 0) {
|
||||
die(
|
||||
`schema drift — table(s) not covered by any reset category: ${uncategorized.join(", ")}\n` +
|
||||
` add them to CATEGORIES in packages/db/scripts/reset-db.mjs (this guard exists so\n` +
|
||||
` new tables can't silently survive resets).`,
|
||||
);
|
||||
}
|
||||
}
|
||||
|
||||
function parseArgs(argv) {
|
||||
const flags = new Set(argv.filter((a) => a.startsWith("--")).map((a) => a.slice(2)));
|
||||
const wantAll = flags.has("all");
|
||||
@@ -75,7 +112,7 @@ async function main() {
|
||||
|
||||
const { cats, autoYes, wantAll } = parseArgs(process.argv.slice(2));
|
||||
if (cats.length === 0) {
|
||||
die("nothing to do — pass --all, --financial, --config, and/or --users");
|
||||
die("nothing to do — pass --all, --financial, --config, --users, and/or --diagnostics");
|
||||
}
|
||||
|
||||
// GATE 1: env opt-in. A production booth never sets this.
|
||||
@@ -86,6 +123,11 @@ async function main() {
|
||||
);
|
||||
}
|
||||
|
||||
// Open early: the drift guard must run BEFORE anything is printed or confirmed, so
|
||||
// an uncategorized table aborts the whole run rather than surviving a "successful" reset.
|
||||
const sqlite = new Database(dbPath);
|
||||
assertNoUncategorizedTables(sqlite);
|
||||
|
||||
// Resolve the ordered, de-duplicated table list for the chosen categories.
|
||||
const tables = [];
|
||||
for (const c of cats) for (const t of CATEGORIES[c]) if (!tables.includes(t)) tables.push(t);
|
||||
@@ -106,7 +148,6 @@ async function main() {
|
||||
if (!ok) die("confirmation did not match — aborted, nothing changed.");
|
||||
}
|
||||
|
||||
const sqlite = new Database(dbPath);
|
||||
try {
|
||||
// FKs OFF for the wipe so we can delete in any order without ordering hazards;
|
||||
// a single transaction makes it all-or-nothing.
|
||||
|
||||
@@ -2,7 +2,7 @@
|
||||
type: concept
|
||||
tags: [parking, observability, diagnostics, logging, frontend, backend]
|
||||
sources: []
|
||||
updated: 2026-07-04
|
||||
updated: 2026-07-08
|
||||
status: open
|
||||
---
|
||||
|
||||
@@ -62,6 +62,16 @@ column — the failed request, error name, component stack, anything), plus pull
|
||||
logged — that's the recursion we guard). Diagnostics must never break the path they observe.
|
||||
- **Bounded.** Frontend queue capped (drops oldest); message/stack/context clamped per row;
|
||||
ingest batch capped.
|
||||
- **Storm coalescing (2026-07-08).** A line identical to the *last persisted row*
|
||||
(level+source+message+path) arriving within **5 min** of its previous occurrence **updates that
|
||||
row** instead of inserting: `context._repeat` counts the fold, `context._firstAt` keeps the first
|
||||
occurrence, `createdAt` moves to the latest (so the storm stays at the top of the newest-first
|
||||
viewer, which badges it `×N`). A *continuous* storm refreshes the window each hit, so it stays ONE
|
||||
row however long it rages. Motivation: the 2026-07-07 field incident — one unreachable controller
|
||||
(`ENETUNREACH`) produced hundreds of identical error rows per minute, evicting unrelated history
|
||||
(see [[button-light-indicator]] for the send-side fix: retry backoff + rate-limited logging).
|
||||
In-memory last-row cache only (a restart just starts a fresh row); if the row was pruned
|
||||
underneath, it falls through to a fresh insert.
|
||||
|
||||
## Retention (offline appliance ⇒ must be bounded)
|
||||
|
||||
@@ -71,6 +81,10 @@ was 30) **and** keep only the newest `LOG_RETENTION_MAX_ROWS` (default 50 000).
|
||||
(unref'd timer) + once at startup. Both env-configurable. Same "prunable, not precious"
|
||||
durability class as `device_events` — the opposite of the append-only ledger.
|
||||
|
||||
Also wipeable on demand: `reset-db.mjs --diagnostics` (new category 2026-07-08 — `app_logs`
|
||||
previously belonged to NO category and silently survived even `--all`; a drift guard in the script
|
||||
now refuses to run if any table is uncategorized). See [[local-dev-workflow]].
|
||||
|
||||
## Container (stdout) logs — the OTHER log store (2026-07-04)
|
||||
|
||||
`docker logs` is a separate, size-bounded store from `app_logs` — it holds **everything**
|
||||
|
||||
@@ -2,7 +2,7 @@
|
||||
type: concept
|
||||
tags: [parking, device, indicator, radar, camera, aux-output, barrier-not-a-door, event-relay]
|
||||
sources: []
|
||||
updated: 2026-06-28
|
||||
updated: 2026-07-08
|
||||
status: settled
|
||||
---
|
||||
|
||||
@@ -72,6 +72,16 @@ aux-output** capability.
|
||||
re-converges to the latest desired state. So the **final state is always authoritative** and a
|
||||
lost/stale packet self-corrects. This also de-dupes (it skips a send when `confirmedOn === desiredOn`),
|
||||
so the input stream never spams the controller.
|
||||
- **Failure backoff + rate-limited logging (2026-07-08).** The first serialized-worker cut re-pumped
|
||||
*immediately* after a FAILED send (`confirmedOn` unchanged → converge again) — correct for a lost
|
||||
packet, but an **unreachable controller** (`ENETUNREACH`, rejects instantly) turned it into a hot
|
||||
loop: hundreds of identical error lines per minute into stdout AND [[app-logs]] (field incident
|
||||
2026-07-07, park-buzi). Now a failed send arms a **retry backoff — 1 s doubling to a 30 s cap,
|
||||
reset on success**; during the window `desiredOn` keeps tracking the truth table and the armed
|
||||
retry converges to whatever it says when it fires (`#finalOff` waives the backoff for the one-shot
|
||||
last-gasp OFF). Logging: only the **first** failure of a streak is logged, then **one summary per
|
||||
minute** (`still failing (attempt N…)`), and a single `info` on recovery. The app_logs sink
|
||||
additionally coalesces identical rows (see [[app-logs]]) as defense in depth.
|
||||
- **Hot-reloads the config (no restart).** The lamp map is reconciled against the live device config
|
||||
at start AND before each event (mirroring [[device-status-monitoring|DeviceMonitor]], which re-reads
|
||||
the device set each tick) — adding/updating/dropping lamps. So a button light added or re-pointed in
|
||||
@@ -102,7 +112,8 @@ Built 2026-06-24 for the first booth (button I1, radar I2, lamp on a spare relay
|
||||
a `radarAlert` event-relay (carrying its own `triggerInput`), so the operator can add arbitrary
|
||||
event-driven blinkers (e.g. R4) without code changes; the 3-state machine itself is unchanged.
|
||||
Covered by `apps/server/src/button-light.test.ts` (the truth table, blink toggling asserted on the
|
||||
device's *confirmed* state, fail-OFF, de-dupe, lamp-added-after-start reconcile, and two independent
|
||||
alert relays on one controller).
|
||||
device's *confirmed* state, fail-OFF, de-dupe, lamp-added-after-start reconcile, two independent
|
||||
alert relays on one controller, and — since 2026-07-08 — backoff cadence on an unreachable
|
||||
controller, log rate-limiting, and single-recovery-line + backoff-reset after success).
|
||||
Related: [[hikvision-radar]], [[entry-double-press]], [[lpr-camera]], [[dingtian-relay]],
|
||||
[[entry-exit-points]], [[barrier-not-a-door]].
|
||||
|
||||
@@ -71,10 +71,16 @@ RESET_ALLOWED=1 DATABASE_URL=/path node packages/db/scripts/reset-db.mjs --all
|
||||
| Flag | Wipes | Keeps |
|
||||
| --- | --- | --- |
|
||||
| `--financial` | `ledger_events` (entry/exit/payment/void/shift/cash/anomaly), `device_events`, `snapshots`, subscription **instances** + credentials/plates, `blocklist` | users, devices, config, tariffs, subscription **plans** |
|
||||
| `--config` | `site_config`, `devices`, `setup_state` (→ re-runs first-run setup), tariffs + versions, subscription plans | everything else |
|
||||
| `--config` | `site_config`, `devices`, `setup_state` (→ re-runs first-run setup), tariffs + versions + **drafts**, subscription plans | everything else |
|
||||
| `--users` | `users`, `roles`, `role_permissions`, auth `sessions` | everything else |
|
||||
| `--diagnostics` | `app_logs` (the unsigned [[app-logs]] store behind `/setup/logs`) | everything else |
|
||||
| `--all` | every table (blank slate) | — |
|
||||
|
||||
**Drift guard** (2026-07-08): before doing anything, the script compares the category union against
|
||||
`sqlite_master` and **refuses if any table is uncategorized** — `app_logs` and `tariff_drafts` had
|
||||
silently survived every reset (including `--all`) because the hand-maintained table list lagged the
|
||||
schema. A new table now forces a deliberate one-line categorization decision.
|
||||
|
||||
> **⚠ `--financial`/`--all` TRUNCATE the append-only, signed [[append-only-event-chain|ledger]].**
|
||||
> That is the anti-fraud record; a *partial* delete would break the hash chain, so a financial reset
|
||||
> wipes the whole ledger back to empty (re-seeding starts a NEW chain under the **same**
|
||||
|
||||
@@ -381,8 +381,11 @@ entrypoint). `DATABASE_URL` in-container is **`/data/parking.sqlite`** (the `par
|
||||
# --financial ledger (entry/exit/payment/void/shift/cash/anomaly) + device_events + snapshots +
|
||||
# subscription INSTANCES/credentials/plates + blocklist. KEEPS users/devices/config/
|
||||
# tariffs/subscription PLANS.
|
||||
# --config site_config, devices, setup_state (re-runs first-run setup), tariffs + versions, plans.
|
||||
# --users users, roles, role_permissions, auth sessions. --all every table.
|
||||
# --config site_config, devices, setup_state (re-runs first-run setup), tariffs + versions
|
||||
# + drafts, plans.
|
||||
# --users users, roles, role_permissions, auth sessions.
|
||||
# --diagnostics app_logs (the /setup/logs store). --all every table.
|
||||
# A drift guard refuses to run if the DB has a table no category covers (2026-07-08).
|
||||
docker exec -it \
|
||||
-e RESET_ALLOWED=1 \
|
||||
-e DATABASE_URL=/data/parking.sqlite \
|
||||
|
||||
+15
@@ -2525,3 +2525,18 @@ deferred (→ delivered by the lab fee breakdown); [[tariff]] lab section gained
|
||||
composer increment-guard paragraph; [[i18n]] now records the "25 Qer 14:30" date standard and the
|
||||
never-toLocaleString-for-dates rule; [[fleet-deployment-komodo]] gained the park-lab stack + tier
|
||||
table (also logging the park-lab addition itself, which had slipped the log).
|
||||
|
||||
## [2026-07-08] update | Log-storm hardening + reset-db drift guard
|
||||
|
||||
Field incident 2026-07-07: an unreachable UHPPOTE (`ENETUNREACH 10.0.10.5:60000`) put the
|
||||
button-light `#pump` worker in a zero-backoff hot loop — hundreds of identical `setAux failed`
|
||||
error rows per minute into [[app-logs]]. Three-layer fix: (1) failed sends now arm a 1s→30s
|
||||
exponential retry (reset on success), with only the first failure logged, one summary/minute
|
||||
after, and one info on recovery ([[button-light-indicator]] §Implementation); (2) LogService
|
||||
coalesces a row identical to the last (level+source+message+path, 5-min refreshing window) by
|
||||
bumping `context._repeat` instead of inserting — the viewer badges `×N` ([[app-logs]]);
|
||||
(3) the user's training reset had ALSO left logs behind: `app_logs` and `tariff_drafts` belonged
|
||||
to no reset-db category, silently surviving even `--all`. Added `--diagnostics` (app_logs), put
|
||||
tariff_drafts under `--config`, and a drift guard that refuses to run when any table is
|
||||
uncategorized ([[local-dev-workflow]], [[appliance-provisioning]] §7d). 8 new tests
|
||||
(3 button-light backoff, 5 coalescing); guard + both new wipes verified on a scratch DB.
|
||||
|
||||
Reference in New Issue
Block a user