tidaldb/tests/e2e/features/08-backups.spec.ts
jordan 77f68d181c
All checks were successful
ci/woodpecker/push/woodpecker Pipeline was successful
verify: flip the two log tripwires post-roll, calibrate the backup assertions
Post-deploy half of the deploy-verification contract for m12-harden-20260831.

Flipped, exactly as each assertion instructed its own successor to do:
- 06-logs.spec.ts: asserted `jsonLines === 0`. JSON_LOGS is live, so it now
  asserts every sampled line parses as JSON. The ANSI check stays pinned at 0.
- 09-operator-authority.spec.ts: asserted JSON_LOGS was absent from the
  StatefulSet. Now asserts JSON_LOGS=1 AND TIDAL_SERVICE_NAME=tidaldb, because
  the second is load-bearing: enabling structured logs makes the app's own
  `service` field win in the fleet's Vector normalize transform, silently
  renaming the log stream tidaldb -> tidal-server and blinding every query keyed
  on it. The fleet's _stream_fields contract pins field names but no legal
  values, so nothing there would have caught the flip.

Calibrated, NOT loosened — the two backup assertions were unpassable by
construction for ~25 minutes every day:
- The schedule fires at 03:30 and measured runs take 9.1-24.8 min (n=15), so the
  newest object is legitimately InProgress during its own window. The "newest
  backup completed cleanly" test now selects the newest FINISHED backup; a
  namespace where nothing has ever finished still fails.
- "no backup stuck in progress" asserted InProgress -> fail, full stop. It now
  bounds in-flight age at 60 min: ~2.4x the slowest success and a quarter of the
  240.0 min timeout that the observed PartiallyFailed runs (2026-08-17/19/25) all
  hit. A gate that cries wolf on a schedule gets muted, and then it is not a gate.

Both thresholds come from reading every backup in the namespace, not from a
guess. Playwright 34/34 and hermetic semantics 5/5 against the deployed image.
2026-08-30 22:06:20 -06:00

227 lines
8.6 KiB
TypeScript
Raw Permalink Blame History

This file contains ambiguous Unicode characters

This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.

/**
* Runbook section 8 — the fleet backup completed and captured every volume.
*
* CAP-013 the fleet backup completed and captured every volume
*
* The selector is the whole lesson here. Sorting every Backup by creation
* timestamp and taking the newest returns a `restore-canary-*` run — 20 items,
* one volume — which reports Completed and proves nothing about the fleet. The
* check must filter on the schedule label that the freshness alert actually
* watches. See BUG-004.
*/
import { expect, test } from '@playwright/test';
import { kubectl } from '../support/cluster';
import { observed, recordJson } from '../support/evidence';
import { BACKUP_NAMESPACE, BACKUP_SCHEDULE } from '../support/env';
/** A fleet backup covering thousands of objects, not a canary's handful. */
const MIN_FLEET_ITEMS = 1_000;
/** Age beyond which a "most recent" backup is itself the finding. */
const MAX_BACKUP_AGE_HOURS = 48;
type BackupStatus = {
phase?: string;
errors?: number;
startTimestamp?: string;
completionTimestamp?: string;
progress?: { itemsBackedUp?: number; totalItems?: number };
};
test.describe('section 8 — backups', () => {
test('the newest fleet-schedule backup completed with every item and every volume', async ({}, testInfo) => {
const list = await observed(testInfo, 'list fleet-schedule backups', () =>
kubectl(
[
'-n',
BACKUP_NAMESPACE,
'get',
'backup.velero.io',
'-l',
`velero.io/schedule-name=${BACKUP_SCHEDULE}`,
'--sort-by=.metadata.creationTimestamp',
'-o',
'jsonpath={range .items[*]}{.metadata.name}{"\\n"}{end}',
],
{ timeoutMs: 45_000 },
),
);
expect(list.code, list.stderr).toBe(0);
const names = list.stdout
.trim()
.split('\n')
.filter((line) => line.trim() !== '');
expect(
names.length,
`no Backup carries label velero.io/schedule-name=${BACKUP_SCHEDULE} — either the ` +
`schedule was renamed or it has never run, and the freshness alert watches this label`,
).toBeGreaterThan(0);
// Pick the newest backup that has actually FINISHED. Selecting `names.at(-1)`
// unconditionally made this test unpassable during the daily backup window:
// the schedule fires at 03:30 and measured runs take 9.124.8 min, so for
// ~25 minutes every day the newest object is legitimately `InProgress` and
// this asserted `phase === 'Completed'` against it. That is a false failure by
// construction — it says "backups are broken" when a backup is working.
// The in-flight case has its own bounded assertion below (see the stuck test).
const finished: string[] = [];
for (const name of names) {
const phaseProbe = await kubectl(
['-n', BACKUP_NAMESPACE, 'get', 'backup.velero.io', name, '-o', 'jsonpath={.status.phase}'],
{ timeoutMs: 45_000 },
);
if (phaseProbe.code === 0 && phaseProbe.stdout.trim() !== 'InProgress') {
finished.push(name);
}
}
expect(
finished.length,
'every fleet-schedule backup is still in flight — nothing has ever finished, which is ' +
'a real failure rather than a timing artifact',
).toBeGreaterThan(0);
const newest = finished[finished.length - 1];
// Guard the selector itself. A canary backup slipping through means the
// filter regressed and this whole test would be verifying the wrong object.
expect(
newest,
'the selected backup must come from the fleet schedule, not a restore canary',
).not.toMatch(/restore-canary/);
const detail = await observed(testInfo, `describe ${newest}`, () =>
kubectl(
['-n', BACKUP_NAMESPACE, 'get', 'backup.velero.io', newest, '-o', 'jsonpath={.status}'],
{ timeoutMs: 45_000 },
),
);
expect(detail.code, detail.stderr).toBe(0);
const status = JSON.parse(detail.stdout) as BackupStatus;
const ageHours = status.completionTimestamp
? (Date.now() - new Date(status.completionTimestamp).getTime()) / 3_600_000
: Number.POSITIVE_INFINITY;
await recordJson(testInfo, 'backup-status', {
name: newest,
phase: status.phase,
errors: status.errors ?? 0,
itemsBackedUp: status.progress?.itemsBackedUp,
totalItems: status.progress?.totalItems,
completedAt: status.completionTimestamp,
ageHours: Number.isFinite(ageHours) ? Number(ageHours.toFixed(1)) : null,
});
expect(status.phase, `${newest} must have completed cleanly`).toBe('Completed');
expect(status.errors ?? 0, `${newest} reported errors`).toBe(0);
expect(
status.progress?.itemsBackedUp,
'every discovered item must be backed up',
).toBe(status.progress?.totalItems);
expect(
status.progress?.totalItems ?? 0,
'a fleet backup should cover thousands of items — a small count means the wrong object',
).toBeGreaterThan(MIN_FLEET_ITEMS);
expect(
ageHours,
`the newest fleet backup is ${ageHours.toFixed(1)}h old — the schedule may have stopped`,
).toBeLessThan(MAX_BACKUP_AGE_HOURS);
const volumes = await observed(testInfo, `pod volume backups for ${newest}`, () =>
kubectl(
[
'-n',
BACKUP_NAMESPACE,
'get',
'podvolumebackups',
'-l',
`velero.io/backup-name=${newest}`,
'-o',
'jsonpath={range .items[*]}{.status.phase}{"\\n"}{end}',
],
{ timeoutMs: 45_000 },
),
);
expect(volumes.code, volumes.stderr).toBe(0);
const phases: Record<string, number> = {};
for (const phase of volumes.stdout.trim().split('\n')) {
if (phase.trim() === '') continue;
phases[phase.trim()] = (phases[phase.trim()] ?? 0) + 1;
}
await recordJson(testInfo, 'pod-volume-backup-phases', phases);
expect(
Object.keys(phases).length,
'the fleet backup must have captured pod volumes',
).toBeGreaterThan(0);
// One failed PVB marks the whole Backup PartiallyFailed and freezes
// velero_backup_last_successful_timestamp, so the fleet alert fires even
// when everything that matters was captured. Every volume must be clean.
expect(
Object.keys(phases).sort(),
`not every PodVolumeBackup completed: ${JSON.stringify(phases)}`,
).toEqual(['Completed']);
});
test('no Velero backup is in flight beyond the measured completion envelope', async ({}, testInfo) => {
const result = await observed(testInfo, 'all backup phases', () =>
kubectl(
[
'-n',
BACKUP_NAMESPACE,
'get',
'backup.velero.io',
'-o',
'jsonpath={range .items[*]}{.metadata.name}{"\\t"}{.status.phase}{"\\t"}{.status.startTimestamp}{"\\n"}{end}',
],
{ timeoutMs: 45_000 },
),
);
expect(result.code, result.stderr).toBe(0);
// CALIBRATED 2026-08-31 against every fleet-daily run in the namespace:
// successful backups complete in 9.124.8 min (n=15), and the observed
// FAILURE mode is a hard 240.0 min timeout that lands PartiallyFailed
// (2026-08-17/19/25). So "in flight" is normal and "in flight for an hour" is
// not. 60 min is ~2.4x the slowest success and a quarter of the timeout.
//
// The previous assertion was `InProgress → fail`, full stop. The daily fires
// at 03:30, so for ~25 minutes every day this test reported the fleet
// unprotected while it was actively being protected. A gate that cries wolf on
// a schedule gets muted, and then it is not a gate.
const STUCK_AFTER_MIN = 60;
const inFlight = result.stdout
.trim()
.split('\n')
.filter((line) => line.trim() !== '')
.map((line) => {
const [name, phase, startTimestamp] = line.split('\t');
const ageMin = startTimestamp
? (Date.now() - new Date(startTimestamp).getTime()) / 60_000
: Number.POSITIVE_INFINITY;
return { name, phase, startTimestamp, ageMin: Number(ageMin.toFixed(1)) };
})
.filter((backup) => backup.phase === 'InProgress' || backup.phase === 'Deleting');
const stuck = inFlight.filter((backup) => backup.ageMin > STUCK_AFTER_MIN);
await recordJson(testInfo, 'in-flight-backups', {
stuckAfterMin: STUCK_AFTER_MIN,
inFlight,
stuck,
});
// A backup wedged InProgress blocks the next scheduled run and silently
// stops the whole fleet from being protected.
expect(
stuck,
`backups in flight past ${STUCK_AFTER_MIN} min: ` +
`${stuck.map((b) => `${b.name}=${b.phase} (${b.ageMin} min)`).join(', ')}`,
).toEqual([]);
});
});