fix(drift): reconcile the drift ledger on deploy and timestamp its history (#1405)

* fix(drift): reconcile the drift ledger on deploy and timestamp its history The drift ledger (persisted history + activity timeline) only advanced when someone clicked re-check on a stack's Drift tab, so the history could sit indefinitely out of sync with the live status: a stack reading "drifted" live while its history still said "resolved". Two corrections: - Deploy and update reconcile the ledger against the just-deployed runtime (the rollback route re-deploys through deployStack, so it is covered), resolving what the change fixed and recording what it left. - Every authoritative reconcile stamps the dossier last-checked time, and the Drift tab labels its history "checked {time}" so a stale finding reads as history, not a claim about the live status above it. Adds the last_drift_check_at column and tests across the ledger reconcile stamp, reconcileStack, the deploy hook, and the panel. * fix(drift): stamp last-checked inside the ledger transaction Move the dossier last-checked stamp into the same transaction as the finding insert/resolve, so the "checked {time}" the Drift tab shows can never persist without the ledger update it describes. The stamp still runs on a no-op authoritative check (a transaction that only stamps), keeping the history "as of" honest. Adds a test that a failed deploy does not reconcile the ledger.
2026-08-04 16:07:55 +00:00 · 2026-06-21 18:20:57 -04:00
parent b9d8e9f490
commit f9c6c5fd09
9 changed files with 193 additions and 10 deletions
@@ -118,6 +118,7 @@ vi.mock('../services/MeshService', () => ({
 }));

 import { ComposeService, getComposeRollbackInfo } from '../services/ComposeService';
+import { DriftLedgerService } from '../services/DriftLedgerService';

 const originalComposeTimeout = process.env.SENCHO_COMPOSE_COMMAND_TIMEOUT_MS;
 const originalStallTimeout = process.env.SENCHO_COMPOSE_STALL_TIMEOUT_MS;
@@ -620,6 +621,48 @@ describe('ComposeService - updateStack prune-on-update', () => {

 // ── withRegistryAuth ───────────────────────────────────────────────────

+describe('ComposeService - drift reconcile hook', () => {
+  it('reconciles the drift ledger after a successful update', async () => {
+    setupAutoCloseSpawn();
+    mockListContainers.mockResolvedValue([]);
+    mockGetGlobalSettings.mockReturnValue({});
+    const spy = vi.spyOn(DriftLedgerService.getInstance(), 'reconcileStack').mockResolvedValue({ detected: 0, resolved: 0 });
+
+    const promise = ComposeService.getInstance(1).updateStack('my-stack');
+    await vi.advanceTimersByTimeAsync(3100);
+    await promise;
+
+    expect(spy).toHaveBeenCalledWith(1, 'my-stack');
+    spy.mockRestore();
+  });
+
+  it('reconciles the drift ledger after a successful deploy', async () => {
+    setupAutoCloseSpawn();
+    mockListContainers.mockResolvedValue([]);
+    mockGetGlobalSettings.mockReturnValue({});
+    const spy = vi.spyOn(DriftLedgerService.getInstance(), 'reconcileStack').mockResolvedValue({ detected: 0, resolved: 0 });
+
+    const promise = ComposeService.getInstance(1).deployStack('my-stack');
+    await vi.advanceTimersByTimeAsync(3100);
+    await promise;
+
+    expect(spy).toHaveBeenCalledWith(1, 'my-stack');
+    spy.mockRestore();
+  });
+
+  it('does not reconcile the ledger when a deploy fails', async () => {
+    setupAutoCloseSpawn(1); // non-zero exit => the deploy rejects before the post-success hook
+    mockListContainers.mockResolvedValue([]);
+    mockGetGlobalSettings.mockReturnValue({});
+    const spy = vi.spyOn(DriftLedgerService.getInstance(), 'reconcileStack').mockResolvedValue({ detected: 0, resolved: 0 });
+
+    const result = await ComposeService.getInstance(1).deployStack('my-stack').then(() => null, (e: Error) => e);
+    expect(result).toBeInstanceOf(Error);
+    expect(spy).not.toHaveBeenCalled();
+    spy.mockRestore();
+  });
+});
+
 describe('ComposeService - withRegistryAuth', () => {
  it('passes default env when no registries configured', async () => {
    mockGetRegistries.mockReturnValue([]);
@@ -228,6 +228,57 @@ describe('DriftLedgerService.reconcile', () => {
    expect(res).toEqual({ detected: 0, resolved: 0 });
    expect(db().getOpenDriftFindings(nodeId, 'rec')).toHaveLength(1);
  });
+
+  it('stamps the dossier last-checked time on every authoritative reconcile, including a no-op', () => {
+    expect(db().getStackDossier(nodeId, 'rec')?.last_drift_check_at ?? null).toBeNull();
+    ledger().reconcile(nodeId, 'rec', reportWith([finding('image-mismatch', 'web')], { stack: 'rec' }));
+    const first = db().getStackDossier(nodeId, 'rec')?.last_drift_check_at;
+    expect(typeof first).toBe('number');
+    // A repeat check that records nothing new still advances the last-checked stamp.
+    ledger().reconcile(nodeId, 'rec', reportWith([finding('image-mismatch', 'web')], { stack: 'rec' }));
+    const second = db().getStackDossier(nodeId, 'rec')?.last_drift_check_at;
+    expect(second as number).toBeGreaterThanOrEqual(first as number);
+  });
+
+  it('does not stamp last-checked for a non-authoritative (unreachable) report', () => {
+    ledger().reconcile(nodeId, 'rec', { stack: 'rec', status: 'unreachable', hasComposeFile: true, hasContainers: false, findings: [] });
+    expect(db().getStackDossier(nodeId, 'rec')?.last_drift_check_at ?? null).toBeNull();
+  });
+});
+
+describe('DriftLedgerService.reconcileStack', () => {
+  const STACK_A = 'recstacka';
+  let dirA: string;
+
+  const composeDir = () => process.env.COMPOSE_DIR as string;
+
+  // A running container on a different image than compose declares => image-mismatch.
+  const driftedContainer = (stack: string) => ({
+    id: `${stack}-c1`, name: `${stack}-web-1`, service: 'web', composeProject: stack, stack,
+    state: 'running', image: 'nginx:1.26', networks: [], volumes: [], ports: [],
+  });
+
+  beforeEach(() => {
+    clearLedger(STACK_A);
+    dirA = path.join(composeDir(), STACK_A);
+    fs.mkdirSync(dirA, { recursive: true });
+    fs.writeFileSync(path.join(dirA, 'compose.yaml'), 'services:\n  web:\n    image: nginx:1.27\n');
+  });
+
+  afterEach(() => {
+    vi.restoreAllMocks();
+    fs.rmSync(dirA, { recursive: true, force: true });
+  });
+
+  it('reconcileStack builds the report, persists drift, and stamps last-checked', async () => {
+    vi.spyOn(DockerController, 'getInstance').mockReturnValue({
+      getDependencySnapshot: vi.fn().mockResolvedValue({ containers: [driftedContainer(STACK_A)], networks: [], volumes: [] }),
+    } as unknown as DockerController);
+    const res = await DriftLedgerService.getInstance().reconcileStack(nodeId, STACK_A);
+    expect(res).toEqual({ detected: 1, resolved: 0 });
+    expect(db().getOpenDriftFindings(nodeId, STACK_A)).toHaveLength(1);
+    expect(typeof db().getStackDossier(nodeId, STACK_A)?.last_drift_check_at).toBe('number');
+  });
 });

 describe('DriftLedgerService.recordBaseline', () => {
@@ -286,6 +337,8 @@ describe('drift route (GET read-only, POST recheck persists)', () => {
    // A passive read must not persist anything.
    expect(db().getOpenDriftFindings(nodeId, STACK)).toHaveLength(0);
    expect(driftActivity(STACK)).toHaveLength(0);
+    // Never reconciled, so the history has no "as of" time.
+    expect(res.body.lastCheckedAt).toBeNull();
  });

  it('POST recheck persists the current drift and returns temporal + ledger', async () => {
@@ -297,6 +350,8 @@ describe('drift route (GET read-only, POST recheck persists)', () => {
    expect(Array.isArray(res.body.ledger)).toBe(true);
    expect(res.body.ledger).toHaveLength(1);
    expect(res.body.ledger[0]).toMatchObject({ service: 'web', kind: 'image-mismatch', resolvedAt: null });
+    // The recheck reconciled, so the history carries an "as of" timestamp.
+    expect(typeof res.body.lastCheckedAt).toBe('number');

    // The transition was recorded exactly once in the activity timeline.
    const acts = driftActivity(STACK);
@@ -994,7 +994,7 @@ async function buildDriftPayload(
  nodeId: number,
  stackName: string,
  reconcile: boolean,
-): Promise<StackDriftReport & { temporal: DriftTemporal; ledger: DriftLedgerEntry[] }> {
+): Promise<StackDriftReport & { temporal: DriftTemporal; ledger: DriftLedgerEntry[]; lastCheckedAt: number | null }> {
  const report = await buildStackDriftReport(nodeId, stackName);
  // Only the on-disk read is best-effort: an unreadable compose is already surfaced
  // by the report as a parse error, so temporal degrades to neutral. computeTemporal
@@ -1016,7 +1016,11 @@ async function buildDriftPayload(
  const ledger: DriftLedgerEntry[] = DatabaseService.getInstance()
    .getRecentDriftFindings(nodeId, stackName, 20)
    .map(r => ({ service: r.service, kind: r.finding_type as DriftFindingKind, message: r.message, detectedAt: r.detected_at, resolvedAt: r.resolved_at }));
-  return { ...report, temporal, ledger };
+  // The ledger reflects the last reconcile (re-check, deploy, or background scan),
+  // not this passive read, so surface when that was: the Drift tab labels the history
+  // "checked {time ago}" and a stale finding reads as history, not current truth.
+  const lastCheckedAt = DatabaseService.getInstance().getStackDossier(nodeId, stackName)?.last_drift_check_at ?? null;
+  return { ...report, temporal, ledger, lastCheckedAt };
 }

 stacksRouter.get('/:stackName/drift', async (req: Request, res: Response) => {
@@ -455,6 +455,13 @@ export class ComposeService {
    // route: bulk, Git-source, App Store, scheduler, and webhook deploys all funnel
    // through this method. Internally guarded; awaited so it cannot race later work.
    await DriftLedgerService.getInstance().recordBaseline(this.nodeId, stackName);
+    // Reconcile the ledger against the just-deployed runtime: findings this deploy
+    // fixed are resolved and any it left are recorded (and surfaced in the activity
+    // feed) now, instead of waiting for someone to open the Drift tab. The rollback
+    // route re-deploys through this method, so it is covered; a failed atomic deploy
+    // instead restores the previous files and throws above, so that recovery path
+    // reconciles on its next deploy or scan, not here. Best-effort internally.
+    await DriftLedgerService.getInstance().reconcileStack(this.nodeId, stackName);
  }

  streamLogs(stackName: string, ws: WebSocket) {
@@ -652,8 +659,10 @@ export class ComposeService {
      throw updateError;
    }
    // Reached only on a successful update; re-baseline so temporal drift compares
-    // against what is now deployed (see deployStack for why this lives here).
+    // against what is now deployed (see deployStack for why this lives here), then
+    // reconcile the ledger against the updated runtime.
    await DriftLedgerService.getInstance().recordBaseline(this.nodeId, stackName);
+    await DriftLedgerService.getInstance().reconcileStack(this.nodeId, stackName);
  }

  public async downStack(stackName: string): Promise<void> {
@@ -90,6 +90,8 @@ export interface StackDossier extends StackDossierFields {
    source_hash?: string | null;
    /** SHA-256 of the parsed compose model at the last deploy (ignores comments/whitespace). */
    rendered_hash?: string | null;
+    /** When the drift ledger was last reconciled for this stack (re-check, deploy, or background scan); null if never. */
+    last_drift_check_at?: number | null;
    created_at: number;
    updated_at: number;
 }
@@ -1284,6 +1286,7 @@ export class DatabaseService {
        custom_notes TEXT NOT NULL DEFAULT '',
        created_at INTEGER NOT NULL,
        updated_at INTEGER NOT NULL,
+        last_drift_check_at INTEGER,
        UNIQUE(node_id, stack_name)
      );

@@ -1669,6 +1672,7 @@ export class DatabaseService {
    private migrateStackDossierHashes(): void {
        this.tryAddColumn('stack_dossiers', 'source_hash', 'TEXT');
        this.tryAddColumn('stack_dossiers', 'rendered_hash', 'TEXT');
+        this.tryAddColumn('stack_dossiers', 'last_drift_check_at', 'INTEGER');
    }

    private migrateGitSourceMultiFile(): void {
@@ -2338,6 +2342,22 @@ export class DatabaseService {
        ).run(nodeId, stackName, sourceHash, renderedHash, now, now);
    }

+    /**
+     * Stamp when the drift ledger was last reconciled for a stack (re-check, deploy,
+     * or background scan). Mirrors setStackDossierHashes: creates a notes-empty row
+     * if none exists, otherwise updates only this column so operator notes and their
+     * updated_at are left untouched.
+     */
+    public setStackDossierDriftCheck(nodeId: number, stackName: string, checkedAt: number): void {
+        const now = Date.now();
+        this.db.prepare(
+            `INSERT INTO stack_dossiers (node_id, stack_name, last_drift_check_at, created_at, updated_at)
+             VALUES (?, ?, ?, ?, ?)
+             ON CONFLICT(node_id, stack_name) DO UPDATE SET
+                last_drift_check_at = excluded.last_drift_check_at`
+        ).run(nodeId, stackName, checkedAt, now, now);
+    }
+
    // --- Stack Drift Findings (the persisted drift ledger) ---

    public insertDriftFinding(f: Omit<StackDriftFindingRow, 'id' | 'resolved_at'>): number {
@@ -6,6 +6,7 @@ import type { DeclaredCompose } from '../helpers/composeDependencyParse';
 import { sha256Hex } from '../utils/hashing';
 import { sanitizeForLog } from '../utils/safeLog';
 import { getErrorMessage } from '../utils/errors';
+import { buildStackDriftReport } from './DriftDetectionService';
 import type { StackDriftReport, StackDriftFinding } from './DriftDetectionService';

 /**
@@ -130,6 +131,7 @@ export class DriftLedgerService {
            return { detected: 0, resolved: 0 };
        }
        const db = DatabaseService.getInstance();
+        const now = Date.now();
        const openByKey = new Map(db.getOpenDriftFindings(nodeId, stackName).map(r => [findingKey(r.service, r.finding_type), r]));
        const currentByKey = new Map(report.findings.map(f => [findingKey(f.service, f.kind), f]));

@@ -141,12 +143,13 @@ export class DriftLedgerService {
        for (const [key, row] of openByKey) {
            if (!currentByKey.has(key)) toResolve.push(row);
        }
-        if (toInsert.length === 0 && toResolve.length === 0) {
-            return { detected: 0, resolved: 0 };
-        }
-
-        const now = Date.now();
+        // Stamp the check time and apply any transitions in one transaction, so the
+        // "checked {time ago}" the Drift tab shows can never persist without the ledger
+        // update it describes. The stamp runs even on a no-op authoritative check (no
+        // transitions), so the history's "as of" stays honest while a stale finding
+        // reads as history rather than as live truth.
        db.getDb().transaction(() => {
+            db.setStackDossierDriftCheck(nodeId, stackName, now);
            for (const f of toInsert) {
                db.insertDriftFinding({
                    node_id: nodeId,
@@ -176,6 +179,23 @@ export class DriftLedgerService {
        return { detected: toInsert.length, resolved: toResolve.length };
    }

+    /**
+     * Build the spatial report for one stack and reconcile it into the ledger.
+     * Used by the deploy and update success hooks (and the rollback route, which
+     * re-deploys through deployStack) so a change resolves the findings it fixed and
+     * records what it left behind. Best-effort: a build or reconcile failure is
+     * logged and swallowed so it never fails the deploy that triggered it.
+     */
+    async reconcileStack(nodeId: number, stackName: string): Promise<DriftReconcileResult> {
+        try {
+            const report = await buildStackDriftReport(nodeId, stackName);
+            return this.reconcile(nodeId, stackName, report);
+        } catch (error) {
+            console.error('[DriftLedger] reconcileStack failed for %s:', sanitizeForLog(stackName), sanitizeForLog(getErrorMessage(error, 'unknown')));
+            return { detected: 0, resolved: 0 };
+        }
+    }
+
    /**
     * Write a drift transition to the stack activity timeline. History-only (no
     * external channel dispatch): a drift signal belongs in the activity feed, not
@@ -47,6 +47,8 @@ Image references are compared after normalizing the implicit Docker Hub registry

 Each time you **re-check** a stack, and after every deploy, Sencho records the findings it sees. The **Drift history** list under the findings shows recent entries with when each was first **detected** and, once it clears, when it was **resolved**. This turns a point-in-time check into a short ledger of how a stack has drifted and recovered over time.

+The history is labelled with when it was last checked. The status badge at the top is always live, recomputed each time you open the tab, while the history reflects the last time the ledger was reconciled. When the two differ, re-check to bring the history up to date.
+
 Drift that appears or clears is also written to the stack's **Activity** timeline, so **Drift detected** and **Drift resolved** events sit alongside deploys and restarts.

 ## Accessing the Drift tab
@@ -23,6 +23,7 @@ interface DriftReport {
  parseError?: string;
  temporal?: { hasBaseline: boolean; sourceChanged: boolean; renderedChanged: boolean };
  ledger?: Array<{ service: string; kind: string; message: string; detectedAt: number; resolvedAt: number | null }>;
+  lastCheckedAt?: number | null;
 }

 function report(partial: Partial<DriftReport>): DriftReport {
@@ -195,10 +196,11 @@ describe('DriftPanel', () => {
    expect(temporal).toHaveAttribute('data-temporal', 'matches');
  });

-  it('renders the persisted drift history with open and resolved entries', async () => {
+  it('renders the persisted drift history with open and resolved entries, labelled with when it was checked', async () => {
    vi.mocked(apiFetch).mockResolvedValue(jsonRes(report({
      status: 'drifted',
      findings: [{ kind: 'image-mismatch', service: 'web', detail: 'image differs' }],
+      lastCheckedAt: Date.now(),
      ledger: [
        { service: 'web', kind: 'image-mismatch', message: 'image differs', detectedAt: Date.now(), resolvedAt: null },
        { service: 'db', kind: 'service-missing', message: 'db not running', detectedAt: Date.now() - 1000, resolvedAt: Date.now() },
@@ -209,5 +211,21 @@ describe('DriftPanel', () => {
    expect(screen.getByText(/drift history/i)).toBeInTheDocument();
    expect(screen.getByText('open')).toBeInTheDocument();
    expect(screen.getByText('resolved')).toBeInTheDocument();
+    // The history is timestamped so a stale row reads as history, not the live status.
+    expect(screen.getByText(/checked/i)).toBeInTheDocument();
+  });
+
+  it('omits the last-checked label when the stack has never been reconciled', async () => {
+    vi.mocked(apiFetch).mockResolvedValue(jsonRes(report({
+      status: 'drifted',
+      findings: [{ kind: 'image-mismatch', service: 'web', detail: 'image differs' }],
+      lastCheckedAt: null,
+      ledger: [
+        { service: 'web', kind: 'image-mismatch', message: 'image differs', detectedAt: Date.now(), resolvedAt: null },
+      ],
+    })));
+    render(<DriftPanel stackName="web" />);
+    await screen.findByTestId('drift-status');
+    expect(screen.queryByText(/checked/i)).not.toBeInTheDocument();
  });
 });
@@ -47,6 +47,9 @@ interface StackDriftReport {
  // Optional so a report from an older remote node (no ledger layer) still renders.
  temporal?: DriftTemporal;
  ledger?: DriftLedgerEntry[];
+  // When the ledger was last reconciled (re-check, deploy, or background scan); null
+  // if never. The history is "as of" this time, not the live status above it.
+  lastCheckedAt?: number | null;
 }

 const LABEL_CLASS = 'font-mono text-[10px] uppercase tracking-[0.18em] text-stat-subtitle';
@@ -229,6 +232,10 @@ export default function DriftPanel({ stackName }: { stackName: string }) {
  const temporal = report?.temporal ? temporalMeta(report.temporal) : null;
  const TemporalIcon = temporal?.icon;
  const ledger = report?.ledger ?? [];
+  // The ledger only moves on a reconcile (re-check, deploy, or background scan), so
+  // label the history with when that last happened: a "resolved"/"open" row then
+  // reads as the state at that check, not a claim about the live status above it.
+  const lastChecked = report?.lastCheckedAt != null ? formatTimeAgo(report.lastCheckedAt) : null;
  const busy = loading || rechecking;

  return (
@@ -306,7 +313,12 @@ export default function DriftPanel({ stackName }: { stackName: string }) {

          {ledger.length > 0 && (
            <section>
-              <div className={cn(LABEL_CLASS, 'mb-1.5')}>drift history</div>
+              <div className={cn(LABEL_CLASS, 'mb-1.5 flex items-center gap-1.5')}>
+                <span>drift history</span>
+                {lastChecked && (
+                  <span className="tracking-normal normal-case text-stat-subtitle/70">· checked {lastChecked}</span>
+                )}
+              </div>
              <div className="rounded-lg border border-muted bg-card/40 px-3 py-1">
                {ledger.map((e, i) => (
                  <LedgerRow key={`${e.service}-${e.kind}-${e.detectedAt}-${i}`} entry={e} />