feat: persist failure journal and bounded retries (F11)
This commit is contained in:
parent
ec3e0c16e0
commit
871182d6d5
15 changed files with 2769 additions and 23 deletions
|
|
@ -146,3 +146,162 @@ Built the full extension locally and smoke-tested against an **isolated** Direct
|
|||
maintenance window, no external cron/token, pauses when the window closes and resumes next night.
|
||||
- UI now shows last-run errors and `paused (window closed)`.
|
||||
- Tests 43/43, typecheck clean.
|
||||
|
||||
## 2026-10-30 — file-library ordering / TUS `uploaded_on` / failure observability
|
||||
|
||||
- User report: fresh files absent from folder list unless filtered by `uploaded_on`; 4,649-item Documents
|
||||
folder; page size raised to 1000 remained slow.
|
||||
- Directus 11.17.4 source check: filtered result is an `_and` subset of unfiltered; no app item cache.
|
||||
Postgres `ORDER BY uploaded_on DESC` = NULLS FIRST, so a large null-date block fills every page before
|
||||
fresh rows. TUS (`TusDataStore.create` + `onUploadFinish`) never sets `uploaded_on`; regular
|
||||
`POST /files` does. Upstream #28042 fixed only in 12.4.0; host stays 11.17.4.
|
||||
- Host checks (pgAdmin): `created_on IS NULL` = **0**; `directus_files` total **39,350**,
|
||||
`uploaded_on IS NULL` = **2,836**, dated = **36,514**.
|
||||
- `uploaded_on` default added successfully: `DEFAULT (now() AT TIME ZONE 'utc')`.
|
||||
- **Backfill UPDATE was not applied**: `uploaded_on IS NULL` still 2,836. Defaults do not backfill
|
||||
history. Re-run `UPDATE directus_files SET uploaded_on = created_on WHERE uploaded_on IS NULL;`
|
||||
(transaction, backup) and verify null count = 0.
|
||||
- Slow thumbnails: backfill only ~95,744 / 661,232 tasks done (~14%); loading 1,000 cards issues 1,000
|
||||
transform requests, most cold → on-demand sharp. Use 25–100 page size; let backfill finish or run
|
||||
outside-window with low concurrency.
|
||||
- Added feature specs F11 (durable `failures.jsonl` + bounded retry + `/failures` + module table) and
|
||||
F12 (host `uploaded_on` remediation). F12 remains `passes:false` until the backfill UPDATE is
|
||||
actually applied and one new TUS upload is verified.
|
||||
|
||||
## 2026-10-30 — production outage: uncommitted pgAdmin DDL held lock (resolved)
|
||||
|
||||
- Symptom: Directus UI/API slow, 500s, health timeouts, container unhealthy. `directus.log` showed
|
||||
repeated `KnexTimeoutError: Timeout acquiring a connection`, `Can't connect to the database`, and
|
||||
60s request aborts.
|
||||
- Root cause: pgAdmin backend **PID 674331** (`pgAdmin 4 - CONN:4204762`) was `idle in transaction`
|
||||
holding a granted `AccessExclusiveLock` on `public.directus_files`. Its last query was the
|
||||
`ALTER TABLE ... ALTER COLUMN uploaded_on SET DEFAULT ...`; it was never committed. All 80 Directus
|
||||
pool connections (4 workers × 20) were active waiting on `Lock/relation` for `directus_files`, so the
|
||||
API pool was exhausted.
|
||||
- A `commit;` from a different pgAdmin connection (PID 674244) does not commit another session's
|
||||
transaction. DDL must be run with auto-commit on or `BEGIN; ...; COMMIT;` in the same session.
|
||||
- Recovery: terminated PID 674331 (`pg_terminate_backend`). Its uncommitted ALTER rolled back; lock
|
||||
released; Directus pool drained; `/server/health` returned `{"status":"ok"}` and container health
|
||||
returned `healthy`.
|
||||
- Re-applied default safely with `lock_timeout=3s`:
|
||||
`DEFAULT (now() AT TIME ZONE 'utc')`. Verified in `information_schema.columns`.
|
||||
- Applied backfill in one transaction with `lock_timeout=5s`, `statement_timeout=30s`:
|
||||
`UPDATE directus_files SET uploaded_on = created_on WHERE uploaded_on IS NULL;` → **UPDATE 2836**,
|
||||
COMMIT. Verified `null_dates = 0`, `dated = 39,350`, zero `Lock` waiters afterwards.
|
||||
- No code/config deploy involved. Raw SQL did not touch `modified_on`/`modified_by`.
|
||||
- Remaining verification: upload one TUS file and confirm non-null `uploaded_on` + `tus_id = null`;
|
||||
then confirm the folder list shows it at top with `-uploaded_on`.
|
||||
- Verified on 2026-10-30 after recovery:
|
||||
- latest 5 TUS uploads all have non-null `uploaded_on`, `tus_id = null`, correct `folder`
|
||||
- `uploaded_on - created_on` ≈ 0–0.24s (default is applied at INSERT, finish is immediate)
|
||||
- `show timezone` = `Etc/UTC`, so `(now() AT TIME ZONE 'utc')` cast to `timestamptz` is correct
|
||||
- zero rows `state = 'idle in transaction'`; no lock waiters
|
||||
- DB/TUS acceptance for F12 is done. Only remaining check: browser Files view shows a fresh TUS file
|
||||
at the top of the unfiltered folder with `sort=-uploaded_on` and `page=1`.
|
||||
- F12 passes. Browser shows fresh files at top when the cards sort control sends `-uploaded_on`.
|
||||
- Apparent "inverted sorting" is a Directus cards UI icon bug, not data. v11.17.4
|
||||
`app/src/layouts/cards/components/header.vue` flips the `sort` glyph for descending, while tabular
|
||||
flips it for ascending. Query semantics are correct: `sort[]=uploaded_on` = ascending (oldest first),
|
||||
`sort[]=-uploaded_on` = descending (newest first). Selecting a field resets direction to ascending.
|
||||
Workaround: toggle until DevTools shows `-uploaded_on`, ignore glyph; or use tabular.
|
||||
|
||||
## 2026-10-30 — F11 persistent failure journal + bounded retry + /failures + module table
|
||||
|
||||
Applicant: coder
|
||||
Feature: F11 — Persistent failure journal, bounded retry, failure API and module view
|
||||
Branch: feat/F11 @ de25e50 (base goal/image-previews @ 7951f82)
|
||||
|
||||
RUN: 2026-10-30T06:26:28Z | coder | /home/rawman/Projects/DirectusExtensions/directus-extension-generate-image-previews | feat/F11 @ de25e50 | npx tsc --noEmit; npm test; npm run build | specs=0 | exit=0 | pass=55 | log=.opencode/tmp/runs/f11-test.log
|
||||
|
||||
Summary:
|
||||
- Added `src/lib/failures.ts`: append-only `<state-dir>/failures.jsonl`, replay of the latest record per
|
||||
`(file_id,preset_key,format)` (key = `completedKeyOf`), corrupt-line tolerance, atomic compaction
|
||||
(unresolved + last 1,000 recovered), and `listFailures` with status filter + limit/offset.
|
||||
- Added `src/lib/retry.ts`: MAX_ATTEMPTS=3, 5m/15m backoff, `nextRetryAt`, `dueRetries`,
|
||||
`journalFailure`/`markRecovered`, and `runDueRetries` (enabled/window/lock gated, targeted bounded
|
||||
batch default 50, grouped by file, full preset + acceptFormat via `warmVariant`, completion + recovered
|
||||
on success, attempt+1 + next retry on failure, compaction under `run.lock`, never throws).
|
||||
- Hooked failure journaling into the upload warm hook, `POST /generate`, and the backfill; successes mark
|
||||
prior failures recovered. Journal writes never alter responses or hook behavior.
|
||||
- Hook scheduler tick now runs due retries first, then the existing backfill.
|
||||
- Added admin-only `GET /image-previews/failures?status=&limit=&offset=` with one batched
|
||||
`directus_files` metadata query (`filename_download`, `type`, `folder`) and ISO/human timestamps.
|
||||
- Module: “Failed previews” table + Refresh (no toasts); API reference includes `/failures`; polling
|
||||
interval unchanged.
|
||||
- Types added; README/AGENTS/project SKILL state-file docs updated.
|
||||
- Tests: `failures.test.ts` (append/replay/latest-state/corrupt/idempotent/compaction/list) and
|
||||
`retry.test.ts` (backoff/exhaustion/due selection/bounded batch/grouping/missing preset/recovered/
|
||||
failure/disabled).
|
||||
|
||||
Files changed:
|
||||
- src/lib/failures.ts (new), src/lib/failures.test.ts (new)
|
||||
- src/lib/retry.ts (new), src/lib/retry.test.ts (new)
|
||||
- src/lib/types.ts, src/lib/warmer.ts, src/lib/backfill.ts
|
||||
- src/hook/index.ts, src/endpoint/index.ts, src/module/module.vue
|
||||
- README.md, AGENTS.md, .opencode/skills/directus-image-previews/SKILL.md, .gitignore
|
||||
- .opencode/progress.txt
|
||||
|
||||
Commands:
|
||||
- `npx tsc --noEmit` → exit 0, 0 errors (`.opencode/tmp/runs/f11-tsc.log`)
|
||||
- `npm test` → exit 0, 55/55 pass (`.opencode/tmp/runs/f11-test.log`)
|
||||
- `npm run build` → exit 0, `dist/app.js` + `dist/api.js` emitted (`.opencode/tmp/runs/f11-build.log`)
|
||||
|
||||
Manual verification steps:
|
||||
1. Cause a failure (unsupported preset format or missing file) from upload, `POST /generate`, and backfill;
|
||||
confirm one line per failure in `<state-dir>/failures.jsonl` and a warn log with `fileId`,
|
||||
`preset_key`, `format`, `attempt`, `next_retry_at`, `error`.
|
||||
2. Inside the maintenance window with no backfill active, wait for the next 15-minute tick; confirm a due
|
||||
pair is retried, success writes `state.jsonl` + a `recovered` event and logs info, failure writes
|
||||
`attempt+1` with 15m backoff (or exhausted at 3).
|
||||
3. `GET /image-previews/failures?status=failed&limit=50&offset=0` as admin: records include file metadata,
|
||||
attempts, first/last failure, next retry raw+ISO/human, status, error, ms; non-admin gets 403.
|
||||
4. Module “Failed previews” table renders and Refresh reloads; no toast/notification appears.
|
||||
|
||||
Not verified locally:
|
||||
- Browser rendering of the new module table (no live Directus/admin session in this run).
|
||||
- Live PM2 `schedule('*/15 * * * *')` tick and maintenance-window retry execution.
|
||||
- Concurrent PM2 append behavior and compaction race with upload-hook appends.
|
||||
|
||||
## 2026-10-30 — F11 review fixes
|
||||
|
||||
- Head: `feat/F11` @ `e10819c`.
|
||||
- Replay now derives attempts from `event.attempt`; fail→recover→fail starts a fresh cycle (attempt 1) and duplicate failed events are idempotent.
|
||||
- Journal writer lock (`failures.lock`, 20×10 ms, 30 s stale): appends serialize, compaction returns `false` if it cannot lock, and append still falls back to writing.
|
||||
- Backfill loads the journal once, skips unresolved failures per pair, and caps journal attempts at `MAX_ATTEMPTS`; recovered pairs still append `recovered`.
|
||||
- Added `/failures` shape/validation tests, retry lock/window tests, fail→recover→fail, attempt cap, and 50-append compaction race tests.
|
||||
|
||||
## 2026-10-30 — F11 second review fixes
|
||||
|
||||
- Implementation head: `feat/F11` @ `7f46493` (progress commit follows).
|
||||
- Journal writes now require the `failures.lock` directory (`owner.json` with random token + pid) and never append unlocked. Blocking acquisition defaults to 10 s / 10 ms poll; timeout drops the event with `image-previews: could not journal failure` and `fileId`/`preset_key`/`format`.
|
||||
- Stale locks are broken only when the owner pid is dead (`process.kill(pid, 0)` → `ESRCH`); mtime staleness removed. Release only removes the lock when `owner.json.token` still matches.
|
||||
- `compactFailures` uses the same lock across read→write temp→rename, returns `false` when it cannot acquire, and uses a pid+token-unique temp filename.
|
||||
- Tests now cover live-owner append refusal, dead-pid recovery, foreign-token release, live-lock compaction refusal, temporarily-held-lock 50-append race, and `planFileTasks` total/resume/skip counting.
|
||||
- `npx tsc --noEmit` 0 errors; `npm test` 69/69 pass; `npm run build` emits both bundles. Logs: `.opencode/tmp/runs/f11-fix2-{tsc,test,build}.log`.
|
||||
- Remaining manual checks: live PM2 scheduler retry tick, browser module rendering, and a real multi-worker compaction/append run.
|
||||
|
||||
## 2026-10-30 — F11 final lock hardening
|
||||
|
||||
- Implementation head: `feat/F11` @ `bc20c6a` (progress commit follows).
|
||||
- Lock is now an atomic `failures.lock` file written with `flag:'wx'`; owner carries `token`, `pid`, `bootId`, `startTime`, `ts`. Identity readers use `/proc/sys/kernel/random/boot_id` and `/proc/<pid>/stat` field 22, with injectable readers for tests.
|
||||
- Dead-lock reclaim runs only under `failures.lock.reclaim` (mkdir guard). Inside the guard it re-stats/re-reads the current owner and unlinks only a dead owner or an unreadable owner older than the 2 s grace. Live owners are never broken; stale guards older than 30 s are removed.
|
||||
- Release unlinks only when the current `owner.token` matches; no unlink on mismatch or read error.
|
||||
- Tests added: concurrent reclaim of a dead lock, missing/corrupt owner grace, PID reuse by bootId and startTime, guard-held reclaim and stale-guard recovery. Existing live-owner timeout, foreign-token release, 50-append race, and compaction-blocked tests stay green.
|
||||
- `npx tsc --noEmit` 0 errors; `npm test` 76/76 pass; `npm run build` emits both bundles. Logs: `.opencode/tmp/runs/f11-lock-{test,build}.log` and `f11-lock-final-*`.
|
||||
- Remaining manual checks: live PM2 multi-worker append/compaction, live scheduler retry tick, browser module rendering.
|
||||
|
||||
## 2026-10-30 — F11 reclaim-guard lifecycle fix
|
||||
|
||||
- Implementation head: `feat/F11` @ `cd973ca` (progress commit follows).
|
||||
- Stale guard removal is now atomic: `rename(guardPath, guardPath.stale.<staleKey>)` with a marker inside the quarantined dir; losers retry instead of deleting a successor guard. Guard writes `owner.json` `{token,pid,ts}` and its `finally` only removes the guard when the token matches.
|
||||
- Added injectable `now` clock. Tests: two waiters on one stale guard (both events survive), foreign-token guard release keeps the successor, plus existing lock/race/compaction tests.
|
||||
- `npx tsc --noEmit` 0; `npm test` 78/78 pass; `npm run build` emits both bundles. Logs: `.opencode/tmp/runs/f11-guard2-{test,build}.log` and `f11-guard-final-*`.
|
||||
- Remaining manual checks: live PM2 multi-worker append/compaction, live scheduler retry tick, browser module rendering.
|
||||
|
||||
## 2026-10-30 — F11 stale-guard snapshot verification
|
||||
|
||||
- Implementation head: `feat/F11` @ `4bd69dd` (progress commit follows).
|
||||
- Stale-guard branch now snapshots `observedMtime` + `observedOwner` before any re-read, quarantines with `guardPath.stale.<pid>.<uuid>`, then verifies the moved directory's owner token (or both null) and mtime against the snapshot. Mismatch restores the successor guard and retries; restore failure returns false without running the action.
|
||||
- Added deterministic successor-replacement test via guard hooks; both appends survive and the successor guard is restored.
|
||||
- `npx tsc --noEmit` 0; `npm test` 79/79 pass; `npm run build` emits both bundles. Logs: `.opencode/tmp/runs/f11-guard3-{test,build}.log` and `f11-guard3-final-*`.
|
||||
- Remaining manual checks: live PM2 multi-worker append/compaction, live scheduler retry tick, browser module rendering.
|
||||
|
|
|
|||
|
|
@ -65,6 +65,7 @@ cache files:
|
|||
settings.json effective config
|
||||
run.json progress (running/done/total/generated/hits/failed/rate/eta/paused/cancelled/error)
|
||||
state.jsonl completed {file_id,preset_key,format} → resume
|
||||
failures.jsonl append-only failure events; replay = latest per task; compacted under run.lock
|
||||
run.lock cluster-wide run lock
|
||||
cancel.flag cancellation request
|
||||
```
|
||||
|
|
|
|||
Loading…
Add table
Add a link
Reference in a new issue