release-2.9.2 (#1566)

* fix: stop full database rewrites on every plugin db call

* fix: restore release video link in 2.9.2 notes

* fix: use TERMIX_PAT in workflows

src/backend/boot.ts

@@ -76,4 +76,8 @@ export async function runCoreBootMigrations(): Promise<void> {
   const { runSshOptionsMigration } =
     await import("./utils/crypto-migration/ssh-options-migration.js");
   await runSshOptionsMigration();
+
+  const { runAuditNoiseCleanup } =
+    await import("./upgrade/audit-noise-cleanup.js");
+  await runAuditNoiseCleanup();
 }

src/backend/database/repositories/audit-log-repository.ts

@@ -1,4 +1,15 @@
-import { and, asc, desc, eq, gte, inArray, lt, lte, sql } from "drizzle-orm";
+import {
+  and,
+  asc,
+  desc,
+  eq,
+  gte,
+  inArray,
+  isNull,
+  lt,
+  lte,
+  sql,
+} from "drizzle-orm";
 import { auditLogs } from "../db/schema.js";
 import type { DatabaseContext } from "./database-context.js";
 import { sqlTimestampDaysAgo } from "./sql-timestamp.js";
@@ -26,6 +37,17 @@ export const AUDIT_RETENTION_DAYS_ENV = "AUDIT_LOG_RETENTION_DAYS";
 export const AUDIT_MAX_ENTRIES_ENV = "AUDIT_LOG_MAX_ENTRIES";
 
 const DEFAULT_MAX_ENTRIES = 10000;
+
+// 2.9.1 logged these on every background plugin query and pushed real
+// entries out of the capped log. They are now audited once per activation.
+export const ROUTINE_PLUGIN_AUDIT_ACTIONS = [
+  "plugin_db_client",
+  "plugin_db_refs",
+  "plugin_kv_get",
+  "plugin_kv_list",
+  "plugin_files_data_dir",
+  "plugin_settings_read_core",
+];
 const PRUNE_TARGET_RATIO = 0.9;
 
 function positiveIntEnv(key: string, env: NodeJS.ProcessEnv): number | null {
@@ -166,6 +188,24 @@ export class AuditLogRepository {
     return rowsAffected(result);
   }
 
+  async deleteRoutinePluginNoise(): Promise<number> {
+    AuditLogRepository.cachedCount = null;
+    const result = await this.context.drizzle
+      .delete(auditLogs)
+      .where(
+        and(
+          isNull(auditLogs.userId),
+          inArray(auditLogs.action, ROUTINE_PLUGIN_AUDIT_ACTIONS),
+        ),
+      );
+
+    if (rowsAffected(result) > 0) {
+      await this.afterWrite();
+    }
+
+    return rowsAffected(result);
+  }
+
   private buildWhere(filters: AuditLogFilters) {
     const conditions = [];
 

src/backend/database/repositories/factory.ts

@@ -78,7 +78,7 @@ export function createCurrentRepositoryWriteHook(
  *
  * Marks the in-memory database dirty and lets DatabaseSaveTrigger's existing
  * debounce coalesce the actual serialize+encrypt, instead of forcing one on
- * every single sample. A lost 2-second window of telemetry on crash is
+ * every single sample. Losing up to 30 seconds of these on a crash is
  * acceptable; blocking the event loop that serves SSH traffic on every metric
  * sample is not.
  */
@@ -128,7 +128,8 @@ export function createCurrentApiKeyRepository(): ApiKeyRepository {
 export function createCurrentAuditLogRepository(): AuditLogRepository {
   return new AuditLogRepository(
     createCurrentRepositoryContext(),
-    createCurrentRepositoryWriteHook("audit_log_repository_write"),
+    // Rows land on every audited call; the audited action saves on its own.
+    createCurrentRepositoryLazyWriteHook("audit_log_repository_write"),
   );
 }
 

src/backend/plugins/ctx.ts

@@ -109,6 +109,11 @@ interface AuditOptions {
   action: string;
   /** Short description of the call shape. Never a value. */
   details?: () => string;
+  /**
+   * Audit only the first success. For handles plugins fetch before every
+   * query: an audit row per call rewrote the whole database each time.
+   */
+  once?: boolean;
 }
 
 /**
@@ -124,6 +129,7 @@ function guarded<Args extends unknown[], Result>(
   fn: (...args: Args) => Promise<Result>,
   options: AuditOptions,
 ): (...args: Args) => Promise<Result> {
+  let audited = false;
   return async (...args: Args): Promise<Result> => {
     // A refusal is audited inside assertCapability, under this action.
     await assertCapability(
@@ -135,7 +141,10 @@ function guarded<Args extends unknown[], Result>(
 
     try {
       const result = await fn(...args);
-      await writeAudit(manifest, options, { success: true });
+      if (!options.once || !audited) {
+        audited = true;
+        await writeAudit(manifest, options, { success: true });
+      }
       return result;
     } catch (error) {
       await writeAudit(manifest, options, {
@@ -242,7 +251,7 @@ export function createPluginContext(
         return null;
       }
     },
-    { action: "kv_get" },
+    { action: "kv_get", once: true },
   );
 
   const kvSet = guarded(
@@ -296,7 +305,7 @@ export function createPluginContext(
         await import("../database/repositories/factory.js");
       return createCurrentPluginStorageRepository().listKeys(pluginId);
     },
-    { action: "kv_list" },
+    { action: "kv_list", once: true },
   );
 
   const filesDataDir = guarded(
@@ -309,7 +318,7 @@ export function createPluginContext(
       await fs.mkdir(dir, { recursive: true });
       return dir;
     },
-    { action: "files_data_dir" },
+    { action: "files_data_dir", once: true },
   );
 
   const dbDefine = guarded(
@@ -329,7 +338,7 @@ export function createPluginContext(
       const { getDb } = await import("../database/db/index.js");
       return getDb();
     },
-    { action: "db_client" },
+    { action: "db_client", once: true },
   );
 
   // The one settings call that leaves the plugin's own namespace, so the one
@@ -341,6 +350,7 @@ export function createPluginContext(
     {
       action: "settings_read_core",
       details: () => "read a core server setting",
+      once: true,
     },
   );
 
@@ -359,7 +369,7 @@ export function createPluginContext(
         userRoles: schema.userRoles,
       };
     },
-    { action: "db_refs" },
+    { action: "db_refs", once: true },
   );
 
   const desktopOpenIsolatedWindow = guarded(
@@ -488,8 +498,8 @@ export function createPluginContext(
       define: (definition) => dbDefine(definition) as never,
       client: () => dbClient() as never,
       refs: () => dbRefs() as never,
-      // Gated but not audited: it follows every write, and the write itself
-      // went through a client() call that already left an audit line.
+      // Gated but not audited: it follows every write, and client() was
+      // already audited when the plugin first asked for it.
       persist: async (options) => {
         await assertCapability(pluginId, "db:own", manifest.capabilities);
         if (!needsExplicitPersist(resolveDatabaseDialect())) return;

src/backend/tests/database/repositories/audit-log-repository.test.ts

@@ -142,6 +142,42 @@ describe("AuditLogRepository", () => {
     ).toEqual(["user-2"]);
   });
 
+  it("clears only background routine plugin entries", async () => {
+    let writeCount = 0;
+    const repo = await createRepository(() => {
+      writeCount += 1;
+    });
+    const entry = (userId: string | null, action: string) =>
+      repo.create({
+        userId,
+        username: "plugin:host-metrics",
+        action,
+        resourceType: "plugin",
+        success: true,
+      });
+
+    await entry(null, "plugin_db_client");
+    await entry(null, "plugin_kv_get");
+    await entry(null, "plugin_kv_set");
+    await entry("user-1", "plugin_db_client");
+    await entry(null, "plugin_as_user");
+    writeCount = 0;
+
+    expect(await repo.deleteRoutinePluginNoise()).toBe(2);
+    expect(writeCount).toBe(1);
+    const left = (
+      await repo.listPage({ filters: {}, limit: 10, offset: 0 })
+    ).logs.map((log) => `${log.userId}:${log.action}`);
+    expect(left.sort()).toEqual([
+      "null:plugin_as_user",
+      "null:plugin_kv_set",
+      "user-1:plugin_db_client",
+    ]);
+
+    expect(await repo.deleteRoutinePluginNoise()).toBe(0);
+    expect(writeCount).toBe(1);
+  });
+
   it("keeps entries when their user is deleted, detaching instead of removing", async () => {
     const repo = await createRepository();
 

src/backend/tests/database/repositories/factory-context.test.ts

@@ -10,6 +10,7 @@ vi.mock("../../../database/db/index.js", () => ({
 }));
 
 const {
+  createCurrentAuditLogRepository,
   createCurrentSessionRepository,
   createCurrentRepositoryContext,
   createCurrentRepositoryWriteHook,
@@ -119,3 +120,42 @@ it("wires SQLite activity to the periodic flush and token changes to immediate p
     else process.env[DATABASE_DIALECT_ENV] = saved;
   }
 });
+
+// Audit rows land on every audited call; a forced save per row rewrote the
+// whole SQLite file each time.
+it("saves SQLite audit rows lazily instead of forcing a save per row", async () => {
+  const saved = process.env[DATABASE_DIALECT_ENV];
+  process.env[DATABASE_DIALECT_ENV] = "sqlite";
+  const { getDb } = await import("../../../database/db/index.js");
+  const { DatabaseSaveTrigger } =
+    await import("../../../utils/database-save-trigger.js");
+  const lazy = vi.spyOn(DatabaseSaveTrigger, "triggerSave").mockResolvedValue();
+  const force = vi.spyOn(DatabaseSaveTrigger, "forceSave").mockResolvedValue();
+  const query = {
+    insert: () => query,
+    values: async () => ({ changes: 1 }),
+    select: () => query,
+    from: async () => [{ count: 1 }],
+  };
+  vi.mocked(getDb).mockReturnValue(
+    query as unknown as ReturnType<typeof getDb>,
+  );
+  try {
+    const repo = createCurrentAuditLogRepository();
+    for (let i = 0; i < 100; i++) {
+      await repo.create({
+        userId: null,
+        username: "plugin:host-metrics",
+        action: "plugin_db_client",
+        resourceType: "plugin",
+        success: true,
+      });
+    }
+    expect(force).not.toHaveBeenCalled();
+    expect(lazy).toHaveBeenCalledTimes(100);
+  } finally {
+    vi.restoreAllMocks();
+    if (saved === undefined) delete process.env[DATABASE_DIALECT_ENV];
+    else process.env[DATABASE_DIALECT_ENV] = saved;
+  }
+});

src/backend/tests/plugins/ctx-db.test.ts

@@ -212,6 +212,48 @@ describe("ctx.db capability", () => {
   });
 });
 
+// Every audit row rewrote the whole SQLite file, and pollers fetch the
+// client before every query (2.9.1 wrote 100 GB in hours).
+describe("ctx audit volume", () => {
+  it("audits the client handle once however often it is fetched", async () => {
+    grants.set("demo", ["db:own"]);
+    const { ctx } = contextFor("demo", ["db:own"]);
+
+    for (let i = 0; i < 100; i++) await ctx.db.client();
+
+    expect(
+      auditEntries.filter((row) => row.action === "plugin_db_client"),
+    ).toHaveLength(1);
+  });
+
+  it("audits kv reads once but every kv write", async () => {
+    grants.set("demo", ["kv:own"]);
+    const { ctx } = contextFor("demo", ["kv:own"]);
+
+    for (let i = 0; i < 5; i++) await ctx.kv.get("k");
+    for (let i = 0; i < 3; i++) await ctx.kv.set("k", i);
+
+    const actions = auditEntries.map((row) => row.action);
+    expect(actions.filter((a) => a === "plugin_kv_get")).toHaveLength(1);
+    expect(actions.filter((a) => a === "plugin_kv_set")).toHaveLength(3);
+  });
+
+  it("still audits a refusal after the first success", async () => {
+    grants.set("demo", ["db:own"]);
+    const { ctx } = contextFor("demo", ["db:own"]);
+    await ctx.db.client();
+
+    grants.set("demo", []);
+    invalidatePluginPermissionCache("demo");
+    await expect(ctx.db.client()).rejects.toThrow();
+
+    const entries = auditEntries.filter(
+      (row) => row.action === "plugin_db_client",
+    );
+    expect(entries.map((row) => row.success)).toEqual([true, false]);
+  });
+});
+
 describe("ctx.kv limits", () => {
   it("refuses a key over the length cap", async () => {
     grants.set("demo", ["kv:own"]);

src/backend/tests/upgrade/audit-noise-cleanup.test.ts

@@ -0,0 +1,41 @@
+import { beforeEach, describe, expect, it, vi } from "vitest";
+
+const deleteRoutinePluginNoise = vi.fn<() => Promise<number>>();
+const forceSave = vi.fn<(reason: string) => Promise<void>>();
+
+vi.mock("../../database/repositories/factory.js", () => ({
+  createCurrentAuditLogRepository: () => ({ deleteRoutinePluginNoise }),
+}));
+vi.mock("../../utils/database-save-trigger.js", () => ({
+  DatabaseSaveTrigger: { forceSave },
+}));
+
+const { runAuditNoiseCleanup } =
+  await import("../../upgrade/audit-noise-cleanup.js");
+
+describe("runAuditNoiseCleanup", () => {
+  beforeEach(() => {
+    deleteRoutinePluginNoise.mockReset();
+    forceSave.mockReset().mockResolvedValue();
+  });
+
+  it("saves once after removing entries", async () => {
+    deleteRoutinePluginNoise.mockResolvedValue(9000);
+
+    await expect(runAuditNoiseCleanup()).resolves.toBe(9000);
+    expect(forceSave).toHaveBeenCalledOnce();
+  });
+
+  it("does not save when there was nothing to remove", async () => {
+    deleteRoutinePluginNoise.mockResolvedValue(0);
+
+    await expect(runAuditNoiseCleanup()).resolves.toBe(0);
+    expect(forceSave).not.toHaveBeenCalled();
+  });
+
+  it("never fails the boot", async () => {
+    deleteRoutinePluginNoise.mockRejectedValue(new Error("locked"));
+
+    await expect(runAuditNoiseCleanup()).resolves.toBe(0);
+  });
+});

src/backend/tests/utils/database-save-trigger.test.ts

@@ -71,7 +71,21 @@ describe("DatabaseSaveTrigger", () => {
     expect(DatabaseSaveTrigger.getStatus().pendingSave).toBe(false);
   });
 
-  it("saves within the max wait even while writes keep coming", async () => {
+  it("saves at most once per 30 seconds while writes keep coming", async () => {
+    vi.useFakeTimers();
+    const save = vi.fn().mockResolvedValue(undefined);
+    DatabaseSaveTrigger.initialize(save);
+    // One sample every 3 seconds used to rewrite the database after each one.
+    for (let tick = 0; tick < 40; tick++) {
+      void DatabaseSaveTrigger.triggerSave("sample");
+      await vi.advanceTimersByTimeAsync(3000);
+    }
+    // 120 seconds: the first save after 2s, then one per 30s window.
+    expect(save.mock.calls.length).toBeGreaterThanOrEqual(4);
+    expect(save.mock.calls.length).toBeLessThanOrEqual(5);
+  });
+
+  it("still saves a steady stream of writes", async () => {
     vi.useFakeTimers();
     const save = vi.fn().mockResolvedValue(undefined);
     DatabaseSaveTrigger.initialize(save);
@@ -79,7 +93,38 @@ describe("DatabaseSaveTrigger", () => {
       void DatabaseSaveTrigger.triggerSave("sample");
       await vi.advanceTimersByTimeAsync(1000);
     }
+    expect(save.mock.calls.length).toBeGreaterThanOrEqual(1);
+    expect(save.mock.calls.length).toBeLessThanOrEqual(2);
+  });
+
+  it("saves a lone write after a quiet period within the debounce", async () => {
+    vi.useFakeTimers();
+    const save = vi.fn().mockResolvedValue(undefined);
+    DatabaseSaveTrigger.initialize(save);
+    void DatabaseSaveTrigger.triggerSave("first");
+    await vi.advanceTimersByTimeAsync(2000);
     expect(save).toHaveBeenCalledTimes(1);
+
+    await vi.advanceTimersByTimeAsync(60_000);
+    void DatabaseSaveTrigger.triggerSave("later");
+    await vi.advanceTimersByTimeAsync(2000);
+    expect(save).toHaveBeenCalledTimes(2);
+  });
+
+  it("does not let a force save be throttled", async () => {
+    vi.useFakeTimers();
+    const save = vi.fn().mockResolvedValue(undefined);
+    DatabaseSaveTrigger.initialize(save);
+    void DatabaseSaveTrigger.triggerSave("sample");
+    await vi.advanceTimersByTimeAsync(2000);
+    expect(save).toHaveBeenCalledTimes(1);
+
+    await vi.advanceTimersByTimeAsync(10);
+
+    // Inside the 30s window, but a critical write saves right away.
+    vi.useRealTimers();
+    await DatabaseSaveTrigger.forceSave("user_create");
+    expect(save).toHaveBeenCalledTimes(2);
   });
 
   it("queues a force save behind an in-flight save", async () => {

src/backend/upgrade/audit-noise-cleanup.ts

@@ -0,0 +1,32 @@
+/**
+ * Clears the audit rows 2.9.1 wrote on every background plugin query.
+ *
+ * They filled the capped audit log and pushed real entries out. Idempotent,
+ * so it runs on every boot, before plugins activate and audit again.
+ */
+
+import { databaseLogger } from "../utils/logger.js";
+import { getErrorMessage } from "../utils/error-message.js";
+import { createCurrentAuditLogRepository } from "../database/repositories/factory.js";
+import { DatabaseSaveTrigger } from "../utils/database-save-trigger.js";
+
+export async function runAuditNoiseCleanup(): Promise<number> {
+  try {
+    const removed =
+      await createCurrentAuditLogRepository().deleteRoutinePluginNoise();
+    if (removed > 0) {
+      await DatabaseSaveTrigger.forceSave("audit_noise_cleanup");
+      databaseLogger.info("Removed routine plugin audit entries", {
+        operation: "audit_noise_cleanup",
+        removed,
+      });
+    }
+    return removed;
+  } catch (error) {
+    databaseLogger.warn("Failed to remove routine plugin audit entries", {
+      operation: "audit_noise_cleanup_failed",
+      error: getErrorMessage(error),
+    });
+    return 0;
+  }
+}

src/backend/utils/database-save-trigger.ts

@@ -3,7 +3,9 @@ import { getErrorMessage } from "./error-message.js";
 import { databaseLogger } from "./logger.js";
 
 const DEBOUNCE_MS = 2000;
-const MAX_DEBOUNCE_WAIT_MS = 30_000;
+// Every save rewrites the whole database file, so background writes (metrics
+// samples, audit rows) may only cause one save per this window.
+const MIN_LAZY_SAVE_GAP_MS = 30_000;
 
 export class DatabaseSaveTrigger {
   private static saveFunction: (() => Promise<void>) | null = null;
@@ -11,7 +13,7 @@ export class DatabaseSaveTrigger {
   private static pendingSave = false;
   private static activeSave: Promise<void> | null = null;
   private static saveTimeout: NodeJS.Timeout | null = null;
-  private static firstTriggerAt: number | null = null;
+  private static lastSaveAt = 0;
   private static _dirty = false;
   private static batch = new AsyncLocalStorage<{
     open: boolean;
@@ -49,22 +51,16 @@ export class DatabaseSaveTrigger {
 
     this._dirty = true;
 
-    if (this.saveTimeout) {
-      clearTimeout(this.saveTimeout);
-    }
+    // A save already pending picks this write up too.
+    if (this.saveTimeout) return;
 
-    // Each call pushes the save back, so steady writes (samples every few
-    // seconds) would keep it from ever running. Cap how long it can wait.
-    const now = Date.now();
-    this.firstTriggerAt ??= now;
     const delay = Math.max(
-      0,
-      Math.min(DEBOUNCE_MS, this.firstTriggerAt + MAX_DEBOUNCE_WAIT_MS - now),
+      DEBOUNCE_MS,
+      this.lastSaveAt + MIN_LAZY_SAVE_GAP_MS - Date.now(),
     );
 
     this.saveTimeout = setTimeout(async () => {
       this.saveTimeout = null;
-      this.firstTriggerAt = null;
 
       try {
         await this.runSave();
@@ -123,7 +119,6 @@ export class DatabaseSaveTrigger {
       clearTimeout(this.saveTimeout);
       this.saveTimeout = null;
     }
-    this.firstTriggerAt = null;
 
     try {
       await this.runSave();
@@ -156,6 +151,7 @@ export class DatabaseSaveTrigger {
       .finally(() => new Promise<void>((resolve) => setImmediate(resolve)));
     this.activeSave = save;
     this.pendingSave = true;
+    this.lastSaveAt = Date.now();
 
     try {
       await save;
@@ -184,7 +180,7 @@ export class DatabaseSaveTrigger {
       clearTimeout(this.saveTimeout);
       this.saveTimeout = null;
     }
-    this.firstTriggerAt = null;
+    this.lastSaveAt = 0;
 
     this.pendingSave = false;
     this.activeSave = null;