fix(faces): defer on unreachable storage, and commit the import path first (#1097)

* fix(faces): defer on unreachable storage, and commit the import path first

The two follow-ups left open by #1091, both consequences of external
photos becoming scannable at all.

**A dropped mount no longer burns the gallery.** ensurePreviewImage
returns null for "this JPEG is corrupt" and "the NFS share is gone"
alike, and faceProcessor marked both 'failed'. Nothing re-queues a
failure automatically and the queue only ever claims 'pending', so a
mount that blinked mid-scan cost the whole event a manual Re-scan —
on external libraries, where network storage drops far more often than
local disk, that is the common case rather than the corner one.

faceProcessor now probes the containing DIRECTORY before failing, and
throws TransientSourceError when it cannot be reached; faceQueue treats
that exactly like SidecarUnavailableError — release to pending, back
off, retry — with the warning rate-limited to one per five minutes,
since an outage hits every photo in the event.

The directory rather than the file is the whole point: a missing file
inside a healthy directory is a broken photo and should still fail, and
it still does. Anything that goes wrong deciding which case it is falls
through to 'failed', because guessing 'transient' on an unknown
condition would retry forever.

**The import commits its path before inserting rows.** enqueueEvent
accepts processing_status NULL (faceProcessor.js:243-246), which these
inserts leave unset, so an admin hitting the toggle or Re-scan during a
long import could queue partial rows while the event still resolved
against the old directory — and burn them to 'failed'.

Moving events.external_path ahead of the loop closes that, and fixes a
pre-existing bug on the same line: an import that died at photo 500 of
1000 used to leave those 500 rows pointing into the new tree while the
event still resolved against the old one, making every one of them
unreadable. Safe to do first because the path is already validated
above, and existing photos are unaffected — photo.source_origin takes
precedence over event.source_mode in both resolvers and is NOT NULL
defaulting to 'managed'.

The #1090 test that asserted a missing source fails needed its setup
corrected rather than its intent: it created no directory at all, which
is now (correctly) a dropped mount. It now creates one, so it tests the
case it always meant to — healthy storage, dead photo.

Verified both fixes discriminate: removing the probe fails the defer
test, and moving the event update back after the loop fails the
ordering test. Face suite 59 passed across 8 suites; the full backend
suite fails the same 10 pre-existing suites as unmodified main, no more.

* fix(faces): stop a dead mount stalling the whole queue

External review, and the first finding is one my own change created.

Deferring by returning the row to 'pending' was a trap: claimNextPhoto
orders by id ascending and the queue defaults to a single worker, so the
same unreachable row becomes the oldest pending one after every backoff
and the worker never reaches a higher id. One dead mount would have
stalled face scanning for the entire install — unrelated events, fresh
uploads, everything. Strictly worse than the permanent 'failed' this set
out to replace.

The row is now left parked in 'processing' with face_started_at intact.
It is not claimable, so the worker moves straight on; the janitor that
already exists returns it to 'pending' past STUCK_TIMEOUT_MS, which is
the retry. No new column and no new timer. The sidecar branch still
releases, because a down sidecar blocks every photo anyway — there is no
other work to get on with.

Second: probing existence was not enough. Unmounting an NFS or SMB share
usually leaves the mountpoint behind as an ordinary empty directory, so
fs.access succeeded on storage that was entirely gone and the photo was
failed anyway — the exact case this was written for. An empty directory
where the photo should live now counts as unreachable. The trade is
deliberate and documented: a directory an admin genuinely emptied is
retried rather than failed, which now costs one attempt per janitor
sweep and nothing else.

Third: a comment in adminExternalMedia claimed source_origin isolates
existing photos from the early external_path update. That is true of
managed rows and false of external ones — resolveExternalPath prefixes
every external row with event.external_path, so importing folder B into
an event referencing folder A rebases the A rows. Pre-existing rather
than introduced here (the update always did this, just later), but the
comment asserted otherwise, so it now says what actually happens and
names the underlying single-base-path limitation.

The deferral test initially passed against the blocking version too —
database state alone cannot tell the fix from the bug. It now inspects
the branch directly, the way the #596 contract tests do, and fails when
releaseToPending is put back or the two branches are merged.

* fix(faces): back off per event, and stop clobbering concurrent scans

Round two of external review.

Parking a row in 'processing' fixed the head-of-line block but not the
cost: every janitor sweep handed the whole dead gallery back, and the
worker walked all of it again — one stat per photo against storage that
may be hard-mounted and slow to time out — before reaching any healthy
event. Every one of those attempts also went through
generatePreviewImage first, which logs an error per photo, so a down
mount produced a recurring flood that the rate-limited warning did
nothing about.

So the backoff is now per EVENT and separate from the janitor:
TransientSourceError carries the event id, the queue records a cooldown,
and claimNextPhoto excludes those events while it lasts. The janitor
keeps doing its own job, which is rescuing rows a crashed worker
abandoned. Cooldown is in memory on purpose — a restart is usually what
follows fixing a mount, so it should retry at once.

Second: committing the event path before the loop means a toggle or
Re-scan firing mid-import can now genuinely queue and finish some of
those rows. The final bulk update was unconditional, so it dragged
'done' rows back to 'pending' for a duplicate sidecar scan and knocked
'processing' rows out from under the worker. It is now whereNull —
only rows nothing has touched are ours to queue.

Also corrected a comment of mine that had gone stale in the same file:
it still described the enqueue as happening after the event path was
written "below", which stopped being true when that update moved above
the loop.

* fix(faces): judge the mount, the path and the file separately

Round three of external review. The probe was too coarse in both
directions.

It read any ENOENT on the photo's own directory as a mount-wide outage,
so a deleted or renamed subfolder — individual/ gone while collages/ is
healthy — deferred the entire event and starved every sibling folder,
renewing the cooldown on each retry. It now judges the EVENT ROOT for
that verdict: root missing, or present-but-empty, is an outage; anything
below a populated root is a broken path and fails.

And it read a listable directory as proof the photo was at fault, so
EACCES on a reconnected share, EIO, or the classic NFS ESTALE handle
were burnt as permanent failures. Only ENOENT now means genuinely gone;
any other error opening the file defers.

The event-wide backoff was also too broad. A reference event can hold
managed uploads alongside imported external ones, and those live in
local storage that is fine — excluding the whole event id left them
unscanned for as long as external rows kept renewing the cooldown, which
during a real outage is indefinitely. The exclusion is now scoped to
external and reference rows.

One of my own tests had modelled the unmount wrongly: it emptied the
photo's subdirectory rather than the event root, which under the
corrected logic is a populated mount with a missing folder — a failure,
not an outage. It now empties the root, which is what an unmount
actually leaves behind.

Dropped the path require the first version of this probe needed; the
event-root form does not.

All three fixes mutation-checked: reverting each one fails the test
written for it. Face suite 69 passed across 9 suites; full backend suite
fails the same 10 pre-existing suites as main, no more.

---------

Co-authored-by: Paul Nothaft <[email protected]>
This commit is contained in:
Paul Nothaft
2026-08-20 14:06:21 +02:00
committed by GitHub
co-authored by Paul Nothaft
parent b7f04f6992
commit 0b886ed942
7 changed files with 727 additions and 22 deletions
+46 -15
View File
@@ -94,6 +94,33 @@ router.post('/events/:id/import-external', adminAuth, requirePermission('photos.
}
}
// Point the event at the new directory BEFORE inserting anything.
//
// Two reasons, both about what a half-finished import leaves behind. The
// update used to run after the loop, so an import that died at photo 500
// of 1000 left those 500 rows carrying external_relpath into the NEW tree
// while the event still resolved against the OLD one — every one of them
// unreadable. And with face detection on, enqueueEvent accepts
// processing_status NULL (faceProcessor.js:243-246), which these inserts
// leave unset, so an admin hitting the toggle or Re-scan mid-import could
// queue those same rows against the stale path and burn them to 'failed'.
//
// Safe to do first for existing MANAGED photos: photo.source_origin takes
// precedence over event.source_mode in both resolvers (photoResolver.js:23,
// :52) and is NOT NULL defaulting to 'managed', so flipping source_mode
// does not touch them.
//
// It does NOT isolate existing EXTERNAL rows — resolveExternalPath prefixes
// every one of them with event.external_path
// (externalMediaService.js:97-102), so importing folder B into an event
// that already references folder A rebases the A rows onto B. That is
// pre-existing: the update always did this, just after the loop instead of
// before it, so moving it changes when the window opens and not whether it
// exists. The underlying limitation is that an event carries a single
// external base path, which makes importing a second folder into it
// incoherent either way — worth its own fix, not this one.
await db('events').where('id', eventId).update({ source_mode: 'reference', external_path });
let imported = 0;
let thumbnailsGenerated = 0;
let thumbnailsFailed = 0;
@@ -112,14 +139,11 @@ router.post('/events/:id/import-external', adminAuth, requirePermission('photos.
// imported after that moment stuck at NULL forever — the toggle endpoint
// only queues rows that already existed when it fired.
//
// Collected during the loop and marked 'pending' only AFTER
// events.external_path is written below. Setting it on insert would publish
// claimable rows while the event still carries the old path — or none, on a
// first import: the face worker polls continuously, resolvePhotoFilePath
// would resolve against the wrong directory, and a multi-minute import
// would leave photos permanently 'failed', a state only an explicit
// Re-scan clears. No video guard needed either way: walkDir collects only
// jpg/jpeg/png/webp.
// The event path is already committed (above), so the enqueue below is
// free of the ordering hazard it used to carry. It stays at the end anyway
// so the setting can be read after the loop, and it only touches rows that
// are still untouched — see the whereNull there. No video guard needed:
// walkDir collects only jpg/jpeg/png/webp.
const importedPhotoIds = [];
// Insert photos
@@ -200,11 +224,10 @@ router.post('/events/:id/import-external', adminAuth, requirePermission('photos.
}
}
// Update event fields
await db('events').where('id', eventId).update({ source_mode: 'reference', external_path });
// Only now does the event resolve to the new directory, so only now is it
// safe to open the queue. Guarded the same way photoProcessor guards it
// The event already resolves to the new directory (set before the loop),
// so the queue is safe to open. Still done here rather than on insert so
// the setting below is read after the loop. Guarded the same way
// photoProcessor guards it
// (both the global flag and the per-event toggle), so installs without the
// feature still never write a face_status. Re-read here rather than before
// the loop so a toggle flipped mid-import is honoured.
@@ -221,12 +244,20 @@ router.post('/events/:id/import-external', adminAuth, requirePermission('photos.
// Chunked because SQLite caps a statement at 999 bound parameters and an
// import can be far larger than that.
if (queueFaces && importedPhotoIds.length) {
let queued = 0;
for (let i = 0; i < importedPhotoIds.length; i += 500) {
await db('photos')
// whereNull, not a blanket set. Committing the event path before the
// loop means a toggle or Re-scan firing mid-import can now genuinely
// queue and even finish some of these rows — so an unconditional
// update would drag 'done' rows back to 'pending' for a duplicate
// scan, and knock 'processing' rows out from under the worker
// mid-flight. Only rows nothing has touched are ours to queue.
queued += await db('photos')
.whereIn('id', importedPhotoIds.slice(i, i + 500))
.whereNull('face_status')
.update({ face_status: 'pending' });
}
logger.info(`Queued ${importedPhotoIds.length} imported external photo(s) for face scanning (event ${eventId})`);
logger.info(`Queued ${queued} of ${importedPhotoIds.length} imported external photo(s) for face scanning (event ${eventId})`);
}
await logActivity(
+97
View File
@@ -34,6 +34,96 @@ class StaleScanError extends Error {
}
}
/**
* Thrown when the photo's source could not be READ, as opposed to being
* unreadable. An NFS or SMB mount that is down, remounting, or refusing
* permissions makes ensurePreviewImage return null exactly like a corrupt
* JPEG does — but one clears itself and the other never will. Marking the
* first 'failed' strands the photo, because the queue only ever claims
* 'pending' and nothing re-queues a failure automatically: a mount that
* blinked during a scan of an external library would cost the whole gallery
* a manual Re-scan.
*/
class TransientSourceError extends Error {
constructor(photoId, reason, eventId) {
super(`Face scan for photo ${photoId} deferred: ${reason}`);
this.name = 'TransientSourceError';
// The queue backs off per EVENT, not per photo: one dead mount makes every
// row in that event unreachable, and probing each of them costs a stat
// against storage that may be hard-mounted and slow to time out.
this.eventId = eventId;
}
}
/**
* Distinguish "this mount is not there" from "this file is not there".
*
* Deliberately probes the containing DIRECTORY rather than the file. A missing
* file inside a healthy directory is a genuinely broken photo and should fail;
* a directory that cannot be reached at all means the storage is gone, and
* every photo under it would otherwise be burnt in a loop.
*
* Returns a reason string when the source looks unreachable, null when it
* looks like a per-photo problem. Any error deciding that is treated as
* per-photo: guessing 'transient' on an unknown condition would retry forever.
*/
async function externalSourceUnreachable(photo) {
if (photo.source_origin !== 'external' && photo.source_origin !== 'reference') return null;
try {
const fs = require('fs').promises;
const { resolvePhotoFilePath } = require('./photoResolver');
const event = await db('events').where({ id: photo.event_id }).first();
if (!event) return null;
const { resolveExternalPath } = require('./externalMediaService');
const filePath = resolvePhotoFilePath(event, photo);
// 1. The EVENT ROOT, not the photo's own directory. This is what decides
// whether the storage is there, and it has to be judged separately: a
// deleted or renamed subfolder (individual/ gone, collages/ still fine)
// also reports ENOENT on the photo's directory, and treating that as an
// outage would defer the whole event and starve the healthy siblings.
const eventRoot = resolveExternalPath(event, '');
try {
await fs.access(eventRoot);
} catch (e) {
return `source root unreachable (${e.code || e.message})`;
}
try {
// Unmounting an NFS or SMB share usually leaves the mountpoint behind as
// an ordinary empty directory, so access() succeeds on storage that is
// entirely gone. An empty root is that outage.
//
// The trade is deliberate: a root an admin genuinely emptied is retried
// rather than failed. That costs one attempt per backoff window, because
// a deferred row parks in 'processing' rather than returning to the front
// of the queue. Burning a gallery on a flapping mount is the worse one.
const entries = await fs.readdir(eventRoot);
if (entries.length === 0) return 'source root is empty (mount not attached?)';
} catch (e) {
return `source root unreadable (${e.code || e.message})`;
}
// 2. The storage is up, so anything wrong from here is about this photo —
// with one exception. A file that exists but cannot be READ (EACCES on a
// reconnected share, EIO, or the classic NFS ESTALE handle) is a
// transient condition wearing a per-file disguise; only ENOENT means the
// photo is genuinely gone.
try {
await fs.access(filePath, fs.constants.R_OK);
} catch (e) {
if (e.code && e.code !== 'ENOENT') {
return `source file unreadable (${e.code})`;
}
}
return null;
} catch (e) {
// Could not even resolve a path — that is a property of this row, not of
// the mount, so let the caller fail it.
return null;
}
}
async function streamToBuffer(stream) {
if (Buffer.isBuffer(stream)) return stream;
const chunks = [];
@@ -89,6 +179,12 @@ async function processPhotoFaces(photoId) {
// photo, not an unsupported one.
const previewKey = await ensurePreviewImage(photo);
if (!previewKey) {
// Before failing the photo, check whether it is the STORAGE that is gone
// rather than the file. ensurePreviewImage returns null for both, but only
// one of them is the photo's fault — see TransientSourceError.
const unreachable = await externalSourceUnreachable(photo);
if (unreachable) throw new TransientSourceError(photoId, unreachable, photo.event_id);
// No preview and no way to make one — the source is missing or corrupt.
// That is a property of this photo, so it fails rather than retries.
await db('photos').where({ id: photoId }).update({
@@ -322,4 +418,5 @@ async function purgePhotoFaces(photoId, trx = db) {
module.exports = {
processPhotoFaces, enqueueEvent, purgeEvent, purgePhotoFaces, StaleScanError,
TransientSourceError,
};
+88 -2
View File
@@ -30,6 +30,7 @@ const { db } = require('../database/db');
const logger = require('../utils/logger');
const { processPhotoFaces } = require('./faceProcessor');
const { SidecarUnavailableError } = require('./faceClient');
const { TransientSourceError } = require('./faceProcessor');
const { isFeatureEnabled } = require('./faceSettings');
const POLL_INTERVAL_MS = parseInt(process.env.FACE_PROCESSOR_POLL_MS || '2000', 10);
@@ -41,6 +42,65 @@ const JANITOR_INTERVAL_MS = 60 * 1000;
// hot loop: claim, fail, release, claim again, thousands of times a minute.
const UNAVAILABLE_BACKOFF_MS = parseInt(process.env.FACE_PROCESSOR_BACKOFF_MS || '30000', 10);
// A dropped mount hits every photo in the event, so the raw message would
// repeat once per claim. Rate-limited the same way faceClient limits its own
// unavailable line, and for the same reason: one warning per outage, not one
// per photo.
// How long an event whose storage is unreachable is left alone. Distinct from
// the janitor's stuck timeout on purpose: the janitor exists to rescue rows a
// crashed worker abandoned, and reusing it here meant that every sweep handed
// the whole dead gallery back to the worker, which then walked all of it again
// — one slow stat per photo against a mount that may be hard-mounted — before
// reaching any healthy event.
const SOURCE_BACKOFF_MS = parseInt(process.env.FACE_SOURCE_BACKOFF_MS || '300000', 10);
// eventId -> epoch ms before which this event's photos are not worth claiming.
// In-memory on purpose: a restart should retry immediately, since a restart is
// usually what follows fixing the mount.
const deferredEvents = new Map();
function deferEvent(eventId) {
if (eventId == null) return;
deferredEvents.set(eventId, Date.now() + SOURCE_BACKOFF_MS);
}
/** Event ids still inside their backoff window; also prunes expired entries. */
function currentlyDeferredEventIds() {
const now = Date.now();
for (const [id, until] of deferredEvents) {
if (until <= now) deferredEvents.delete(id);
}
return [...deferredEvents.keys()];
}
/**
* Exclude only the rows the outage actually affects.
*
* A reference event can hold managed uploads alongside its imported external
* ones, and those live in local storage that is fine. Excluding the whole
* event id would leave them unscanned for as long as external rows keep
* renewing the cooldown — which, during a real outage, is indefinitely.
*/
function applySourceBackoff(query, excludeEventIds) {
if (!excludeEventIds.length) return query;
return query.whereNot(function () {
this.whereIn('event_id', excludeEventIds)
.whereIn('source_origin', ['external', 'reference']);
});
}
const SOURCE_LOG_INTERVAL_MS = 5 * 60 * 1000;
let lastUnreachableLogAt = 0;
function logUnreachableSource(message) {
const now = Date.now();
if (now - lastUnreachableLogAt < SOURCE_LOG_INTERVAL_MS) return;
lastUnreachableLogAt = now;
logger.warn(
`faceQueue: ${message}. Photos stay queued and will be retried — check the `
+ 'external media mount. Further identical warnings are suppressed for 5 minutes.'
);
}
let running = false;
let workerHandles = [];
let janitorHandle = null;
@@ -57,11 +117,12 @@ function isPostgres() {
* Same two-path approach as backgroundProcessor: SKIP LOCKED on Postgres so
* multiple pods race cleanly, a status-guarded UPDATE on SQLite.
*/
async function claimNextPhoto() {
async function claimNextPhoto(excludeEventIds = []) {
if (isPostgres()) {
return db.transaction(async (trx) => {
const row = await trx('photos')
.where('face_status', 'pending')
.modify((q) => applySourceBackoff(q, excludeEventIds))
.orderBy('id', 'asc')
.forUpdate()
.skipLocked()
@@ -78,6 +139,7 @@ async function claimNextPhoto() {
return db.transaction(async (trx) => {
const row = await trx('photos')
.where('face_status', 'pending')
.modify((q) => applySourceBackoff(q, excludeEventIds))
.orderBy('id', 'asc')
.first();
if (!row) return null;
@@ -114,7 +176,7 @@ async function workerLoop(workerIdx) {
let claimed;
try {
claimed = await claimNextPhoto();
claimed = await claimNextPhoto(currentlyDeferredEventIds());
} catch (e) {
logger.warn(`faceQueue[${workerIdx}]: claim error`, { error: e.message });
await sleep(POLL_INTERVAL_MS);
@@ -129,6 +191,9 @@ async function workerLoop(workerIdx) {
try {
await processPhotoFaces(claimed.id);
} catch (err) {
// The sidecar being down stops EVERY photo, so returning this one to
// 'pending' and backing off costs nothing — there is no other work to
// get on with.
if (err instanceof SidecarUnavailableError) {
// Retry, don't fail. faceClient already rate-limits the log line.
await releaseToPending(claimed.id).catch(() => {});
@@ -136,6 +201,27 @@ async function workerLoop(workerIdx) {
continue;
}
// An unreachable source is per-EVENT, not global: other events are
// still perfectly scannable. Releasing to 'pending' here would be a
// trap — claimNextPhoto orders by id ascending, so the single default
// worker would reclaim this same row after every backoff and never
// reach any higher id. One dead mount would stall face scanning for
// the whole install.
//
// So leave it parked in 'processing' with its face_started_at intact.
// The worker moves straight on to the next claimable row, and the
// janitor returns this one to 'pending' once it passes
// STUCK_TIMEOUT_MS — which is exactly the "try again later" this
// needs, using machinery that already exists.
if (err instanceof TransientSourceError) {
// Back the whole EVENT off, not just this row. Its siblings are on the
// same storage and would each cost another failed preview attempt —
// which also logs — before landing here again.
deferEvent(err.eventId);
logUnreachableSource(err.message);
continue;
}
logger.error(`faceQueue[${workerIdx}]: photo ${claimed.id} failed`, {
error: err.message,
stack: err.stack,