Skip to content

fix: two boot/federation log errors — duplicate-key upserts and peer-pull denial spam - #5827

Merged
atomantic merged 3 commits into
mainfrom
cos/task-mtjono6k/agent-4bfec75e
Sep 2, 2026
Merged

fix: two boot/federation log errors — duplicate-key upserts and peer-pull denial spam#5827
atomantic merged 3 commits into
mainfrom
cos/task-mtjono6k/agent-4bfec75e

Conversation

@atomantic

Copy link
Copy Markdown
Owner

Summary

Fixes two unexplained error lines in the running instance's PM2 logs.

1. 🪄 catalog migrations failed at boot: ON CONFLICT DO UPDATE command cannot affect row a second time

Postgres refuses a multi-row INSERT … ON CONFLICT (key) DO UPDATE whose VALUES list names the same conflict key twice. Two places build exactly that statement from data that makes no uniqueness promise:

  • mediaAssetIndex reconcile batches every on-disk image + video into chunked upserts. One repeated gallery filename or video-history id threw, and because it is the last step of the boot catalog-migration block, the throw aborted the block and left the media asset index permanently stale — it never upserted or pruned again.
  • memorySync.applyRemoteChanges batches a remote peer's payload inside a transaction, so one repeated id there rolls back the entire apply — not just its batch — every sync cycle, for as long as the peer keeps sending it. This one had no test coverage at all.

Both now collapse duplicates first through a shared dedupeByKey helper in server/lib/arrayUtils.js. Tie-break differs per table because the conflict rules differ: the media index keeps the last occurrence (what a sequential upsertAsset loop leaves), while memory sync keeps the newest updated_at, so a peer's payload ordering can't flip a last-writer-wins outcome. An unparseable clock sorts below every real one rather than NaN-comparing false and winning — otherwise a malformed copy displaces a good one and then fails the statement on a row we already had intact.

2. ❌ Route error [GET /api/sync/usage/checksum]: peer not authorized for this record

A peer that can't be identified re-polls its sync categories every few seconds, and every denied pull logged this at error level — roughly every 10s per category, forever. peerPullAuthorization already logs a deliberately throttled 🔒 line (once per caller per boot) for exactly this, so the route-level line added nothing and buried real errors.

The 403 is now severity: 'warning', the existing errorHandler mechanism for expected, already-classified denials (precedents: mediaJobs.js, imageClean.js, remoteDesktop.js). The response the caller receives is unchanged.

Strict mode previously threw with no log at all — combined with the above that would leave a user who enabled federation.strictPullAuthorization with no indication of why a peer stopped syncing. It now logs the same throttled refusal alwaysEnforce does, which collapses the two identical enforce branches into one.

Test plan

  • server/services/memorySync.db.test.jsnew DB-backed suite for applyRemoteChanges (the federation write path had none): duplicate id doesn't abort the transaction, tie-break is by updated_at not payload order, malformed clock loses, and the existing last-writer-wins behavior still holds.
  • server/services/mediaAssetIndex/db.test.js — reconcile survives repeated refs on disk.
  • Both regression tests were verified to fail with the exact production error (ON CONFLICT DO UPDATE command cannot affect row a second time) when the dedup is removed, then pass with it.
  • server/lib/arrayUtils.test.jsdedupeByKey unit tests incl. the custom-comparator path.
  • server/services/sharing/peerPullAuthorization.test.js — asserts the 403 carries severity: 'warning' and that strict mode now logs the throttled 🔒 line.
  • npm run test:db — 32 files / 279 tests pass (includes db.guards.test.js, which validates the new DB_TEST_INCLUDE entry).
  • Full server suite passes; the only failures are Python-dependent suites (imageTo3d, voice, videoGen) failing on Python was not found in this environment, unrelated to these files.

Notes

dedupeByKey lands in the existing arrayUtils.js rather than a new module, with the barrel export and server/lib/README.md row the module-maintenance rule requires. Its docblock carries the Postgres invariant so the next batching upsert site finds it instead of re-deriving the workaround.

A boot-time reconcile was failing with "ON CONFLICT DO UPDATE command
cannot affect row a second time", which aborted the whole catalog
migration step and left the media asset index permanently stale.

Postgres refuses a multi-row INSERT ... ON CONFLICT DO UPDATE whose
VALUES list names the same conflict key twice. Two places build exactly
that statement from data that makes no uniqueness promise:

- mediaAssetIndex reconcile batches every on-disk image and video into
  chunked upserts, so one repeated gallery filename or video-history id
  threw and froze the entire index.
- memorySync.applyRemoteChanges batches a remote peer's payload inside a
  transaction, so one repeated id there would roll back the whole apply,
  every sync cycle, for as long as the peer kept sending it.

Both now collapse duplicates first via a shared dedupeByKey helper. The
media index keeps the last occurrence (what a sequential upsert loop
leaves); memory sync keeps the newest updated_at, so a peer's payload
ordering cannot flip a last-writer-wins outcome.

Adds DB-backed regression tests for both, each verified to reproduce the
original Postgres error without the fix.
A peer that cannot be identified re-polls its sync categories every few
seconds, and each denied pull logged a generic "Route error [GET
/api/sync/usage/checksum]: peer not authorized for this record" at error
level. The module already logs a deliberately throttled line (once per
caller per boot) for exactly this, so the route-level line added nothing
and buried real errors in the log.

Mark the 403 severity: 'warning', the existing errorHandler mechanism for
expected, already-classified denials. The response the caller receives is
unchanged.

Strict mode previously threw with no log at all, which combined with the
above would leave a user who enabled federation.strictPullAuthorization
with no indication of why a peer stopped syncing. It now logs the same
throttled refusal alwaysEnforce does, collapsing the two identical
enforce branches into one.
…uplicates

The last-writer-wins comparator used a bare Date.parse comparison, so a
malformed updated_at compared false against a valid one and won the
collapse. That copy then went to a timestamptz column and failed the
statement, losing a row that arrived intact in the same payload.

Sort NaN explicitly below every real clock, and keep the first copy on a
tie to match the SQL's strict `>`.
@atomantic
atomantic merged commit c0d3f17 into main Sep 2, 2026
7 checks passed
@atomantic
atomantic deleted the cos/task-mtjono6k/agent-4bfec75e branch September 2, 2026 06:49
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant