Multi-Hoster-Upload/tests/upload-log.test.js
Administrator eeec1d150c fix(queue): completed files no longer reappear in the queue after restart
Closing the app (especially during an active upload or on a hard kill) and
reopening sometimes left already-uploaded files sitting in the queue as if
still pending. Root cause is three layers stacked:

1. Persist-starvation: persistQueueStateSoon() reset a 10s debounce on every
   progress event, so during an upload the on-disk queue snapshot was never
   rewritten and stayed frozen at the pre-upload state (all jobs "preview").
2. The beforeunload sync flush only covers a clean close; a hard kill / crash
   leaves that stale snapshot on disk.
3. Startup auto-dedup only dropped jobs with status "done". The completed
   files were stored as "preview" in the stale snapshot, so they survived and
   reappeared.

Fix (mechanism-independent — holds whether the stale snapshot came from
starvation, a mid-upload close race, or a hard kill):

FIX A (core, durable): the upload log is the source of truth. Each persisted
snapshot is now stamped with savedAt; on restart any restored job whose newest
matching log entry is timestamped at/after floor(savedAt) is dropped regardless
of status — it provably completed after the snapshot, so a "preview" row for it
is a ghost. lib/queue-dedup.js gains an additive 3rd savedAt param; without
savedAt or without log timestamps it behaves exactly as before (the 5 canary
tests stay green, so intentional re-uploads of older files still survive).

FIX B: new lib/throttle-timer.js with a max-wait. During uploads the snapshot
is now written at most ~20s into a continuous progress burst instead of never;
idle stays a pure debounce. The fallback shim honors max-wait too, so a missing
library can never silently reintroduce the starvation.

FIX C: the synchronous close-write retries renameSync on EBUSY/EPERM/EACCES and
uses a pid-unique tmp (de-conflicts it from config-store._atomicWrite's fixed
.tmp). A startup sweep reclaims orphaned <config>.<pid>.tmp files left by a hard
kill between write and rename.

lib/upload-log.js extracts formatUploadLogLine + parseUploadLogLine from main.js
so the real writer -> reader -> gate seam is unit-tested (a future log-format or
epoch-basis change can no longer pass green while breaking the fix).

Verified: 334/334 tests green (incl. throttle fake-clock starvation/maxWait,
ts-gate multi-hoster partial-completion, and the real-format seam tests), ESLint
clean, smoke-boot identical to baseline, and an adversarial multi-agent review
(15 findings, 14 refuted, 1 low — the tmp orphan, now swept) on the diff.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
2026-06-19 04:35:27 +02:00

53 lines
2.6 KiB
JavaScript

const { test } = require('node:test');
const assert = require('node:assert');
const { formatUploadLogLine, parseUploadLogLine } = require('../lib/upload-log');
const { partitionRestoredJobsByLog } = require('../lib/queue-dedup');
function previewJob(fileName, hoster) {
return { status: 'preview', fileName, hoster, file: `C:/dl/${fileName}` };
}
test('writer -> reader round trip: parsed ts is the same epoch frame as the source Date getTime', () => {
const d = new Date(2026, 5, 19, 12, 0, 30);
const line = formatUploadLogLine(d, 'voe.sx', 'https://voe.sx/x', 'a.mkv');
const parsed = parseUploadLogLine(line);
assert.equal(parsed.hoster, 'voe.sx');
assert.equal(parsed.fileName, 'a.mkv');
assert.equal(parsed.ts, d.getTime(), 'parser ts must equal the writer Date epoch (no tz shift)');
});
test('SEAM: a real appendUploadLog-format line drops a preview ghost vs a savedAt taken BEFORE completion', () => {
const completion = new Date(2026, 5, 19, 12, 0, 30);
const line = formatUploadLogLine(completion, 'voe.sx', 'link', 'a.mkv');
const parsed = parseUploadLogLine(line);
const savedAt = completion.getTime() - 5000;
const { removed, kept } = partitionRestoredJobsByLog([previewJob('a.mkv', 'voe.sx')], [parsed], savedAt);
assert.equal(removed.length, 1, 'a file logged after the snapshot is a ghost and must drop');
assert.equal(kept.length, 0);
});
test('SEAM: the same real line is KEPT vs a savedAt taken AFTER completion (intentional re-upload)', () => {
const completion = new Date(2026, 5, 19, 12, 0, 30);
const parsed = parseUploadLogLine(formatUploadLogLine(completion, 'voe.sx', 'link', 'a.mkv'));
const savedAt = completion.getTime() + 5000;
const { removed, kept } = partitionRestoredJobsByLog([previewJob('a.mkv', 'voe.sx')], [parsed], savedAt);
assert.equal(removed.length, 0, 'an older upload than the snapshot is a deliberate re-queue and must survive');
assert.equal(kept.length, 1);
});
test('parseUploadLogLine skips comments, blanks and malformed lines', () => {
assert.equal(parseUploadLogLine('# fileuploader log'), null);
assert.equal(parseUploadLogLine(''), null);
assert.equal(parseUploadLogLine(' '), null);
assert.equal(parseUploadLogLine('only|three|parts|here'), null);
assert.equal(parseUploadLogLine(null), null);
assert.equal(parseUploadLogLine(42), null);
});
test('parseUploadLogLine: missing/garbage timestamp yields ts=undefined (legacy lines still match by name)', () => {
const parsed = parseUploadLogLine('|voe.sx|link||a.mkv|');
assert.equal(parsed.hoster, 'voe.sx');
assert.equal(parsed.fileName, 'a.mkv');
assert.equal(parsed.ts, undefined);
});