From eeec1d150c9e02cd7f98f0893b660bda795aeae7 Mon Sep 17 00:00:00 2001 From: Administrator Date: Fri, 19 Jun 2026 04:35:27 +0200 Subject: [PATCH] fix(queue): completed files no longer reappear in the queue after restart MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit 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 ..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) --- lib/queue-dedup.js | 49 +++++++++---- lib/throttle-timer.js | 59 ++++++++++++++++ lib/upload-log.js | 31 ++++++++ main.js | 66 +++++++++++++---- renderer/app.js | 59 +++++++++++----- renderer/index.html | 1 + tasks/todo.md | 72 ++++++++++++++----- tests/queue-dedup.test.js | 89 +++++++++++++++++++++++ tests/throttle-timer.test.js | 133 +++++++++++++++++++++++++++++++++++ tests/upload-log.test.js | 52 ++++++++++++++ 10 files changed, 548 insertions(+), 63 deletions(-) create mode 100644 lib/throttle-timer.js create mode 100644 lib/upload-log.js create mode 100644 tests/throttle-timer.test.js create mode 100644 tests/upload-log.test.js diff --git a/lib/queue-dedup.js b/lib/queue-dedup.js index 384f304..3614c5d 100644 --- a/lib/queue-dedup.js +++ b/lib/queue-dedup.js @@ -7,18 +7,21 @@ // runtime and tests — no drift. // // Behaviour: on launch the restored queue is compared against the lifetime -// upload log. ONLY genuinely-completed ('done') jobs that also appear in the -// log are dropped — that's pure decluttering of work that already finished. +// upload log. Two rules drop a job: +// 1) a 'done' job whose fileName|hoster appears in the log (declutter of +// already-finished work), and +// 2) ANY job (incl. preview) whose newest matching log entry is timestamped +// at/after the snapshot's savedAt — it provably completed AFTER the queue +// was last persisted, so a restored 'preview' row for it is a stale ghost. // -// Pending jobs (preview / queued) and failed ones (error / aborted) are NEVER -// dropped here, even if a same-name+hoster line exists in the log. Those are -// work the user intentionally has queued (often a deliberate re-upload of a -// file that was uploaded before). The old code filtered on log-presence alone, -// regardless of status, so the ENTIRE restored queue vanished on the next -// restart/update whenever the files had been uploaded previously — surfacing as -// an empty "Dateien hierhin ziehen oder klicken" queue. Manual log import -// (importUploadLog) stays separate and explicit for users who do want bulk -// dedup of pending jobs. +// Rule 2 only fires when a savedAt is passed AND the log carries timestamps; +// without them this falls back to rule 1 alone. That fallback is the invariant +// the canary tests pin: a pending job matching an OLDER log line (ts < savedAt, +// or no ts at all) is KEPT — it's an intentional re-upload of a file uploaded +// before, not a ghost. The old code filtered on log-presence alone, regardless +// of status, so the ENTIRE restored queue vanished on the next restart/update +// whenever the files had been uploaded previously. Manual log import +// (importUploadLog) stays separate and explicit for bulk dedup. (function (root) { 'use strict'; @@ -34,19 +37,35 @@ * @param {Array<{fileName:string,hoster:string}>} logEntries * @returns {{ kept: Array, removed: Array }} */ - function partitionRestoredJobsByLog(jobs, logEntries) { + function partitionRestoredJobsByLog(jobs, logEntries, savedAt) { const kept = []; const removed = []; if (!Array.isArray(jobs) || jobs.length === 0) return { kept, removed }; const logKeys = new Set(); + const logMaxTs = new Map(); for (const e of (Array.isArray(logEntries) ? logEntries : [])) { - if (e && e.fileName && e.hoster) logKeys.add(_key(e.fileName, e.hoster)); + if (e && e.fileName && e.hoster) { + const k = _key(e.fileName, e.hoster); + logKeys.add(k); + if (typeof e.ts === 'number' && isFinite(e.ts)) { + const prev = logMaxTs.get(k); + if (prev === undefined || e.ts > prev) logMaxTs.set(k, e.ts); + } + } } + const savedAtFloor = (typeof savedAt === 'number' && isFinite(savedAt)) + ? Math.floor(savedAt / 1000) * 1000 + : null; + for (const job of jobs) { - const isDone = job && job.status === 'done' && job.fileName && job.hoster; - if (isDone && logKeys.has(_key(job.fileName, job.hoster))) { + const hasIds = job && job.fileName && job.hoster; + const k = hasIds ? _key(job.fileName, job.hoster) : null; + const doneInLog = job && job.status === 'done' && hasIds && logKeys.has(k); + const uploadedAfterSnapshot = savedAtFloor !== null && k !== null + && logMaxTs.has(k) && logMaxTs.get(k) >= savedAtFloor; + if (doneInLog || uploadedAfterSnapshot) { removed.push(job); } else { kept.push(job); diff --git a/lib/throttle-timer.js b/lib/throttle-timer.js new file mode 100644 index 0000000..c4a9d52 --- /dev/null +++ b/lib/throttle-timer.js @@ -0,0 +1,59 @@ +(function (root) { + 'use strict'; + + function makeThrottleTimer(opts) { + const o = opts || {}; + const now = typeof o.now === 'function' ? o.now : (() => Date.now()); + const schedule = typeof o.schedule === 'function' + ? o.schedule + : ((cb, ms) => setTimeout(cb, ms)); + const clear = typeof o.clear === 'function' ? o.clear : ((h) => clearTimeout(h)); + + let handle = null; + let burstStart = null; + let pendingFn = null; + + function fire() { + handle = null; + burstStart = null; + const fn = pendingFn; + pendingFn = null; + if (typeof fn === 'function') fn(); + } + + function request(fn, delay, maxWait) { + if (typeof fn === 'function') pendingFn = fn; + const t = now(); + if (burstStart === null) burstStart = t; + let wait = typeof delay === 'number' && delay >= 0 ? delay : 0; + if (typeof maxWait === 'number' && maxWait >= 0) { + const remaining = maxWait - (t - burstStart); + wait = Math.min(wait, remaining < 0 ? 0 : remaining); + } + if (handle !== null) clear(handle); + handle = schedule(fire, wait); + } + + function flushSync() { + if (handle !== null) { clear(handle); handle = null; } + burstStart = null; + const fn = pendingFn; + pendingFn = null; + if (typeof fn === 'function') fn(); + } + + function cancel() { + if (handle !== null) { clear(handle); handle = null; } + burstStart = null; + pendingFn = null; + } + + function isPending() { return handle !== null; } + + return { request, flushSync, cancel, isPending }; + } + + const api = { makeThrottleTimer }; + if (typeof module !== 'undefined' && module.exports) module.exports = api; + else if (root) root.ThrottleTimer = api; +})(typeof window !== 'undefined' ? window : this); diff --git a/lib/upload-log.js b/lib/upload-log.js new file mode 100644 index 0000000..0f04630 --- /dev/null +++ b/lib/upload-log.js @@ -0,0 +1,31 @@ +(function (root) { + 'use strict'; + + function _pad(n) { return String(n).padStart(2, '0'); } + + function formatUploadLogLine(date, hoster, link, fileName) { + const d = date instanceof Date ? date : new Date(); + const dateStr = `${d.getFullYear()}-${_pad(d.getMonth() + 1)}-${_pad(d.getDate())} ` + + `${_pad(d.getHours())}:${_pad(d.getMinutes())}:${_pad(d.getSeconds())}`; + return `${dateStr}|${hoster}|${link}||${fileName}|\n`; + } + + function parseUploadLogLine(line) { + if (typeof line !== 'string') return null; + const trimmed = line.trim(); + if (!trimmed || trimmed.startsWith('#')) return null; + const parts = trimmed.split('|'); + if (parts.length < 5) return null; + const hoster = (parts[1] || '').trim(); + const fileName = (parts[4] || '').trim(); + if (!hoster || !fileName) return null; + const tsStr = (parts[0] || '').trim(); + const tsParsed = tsStr ? Date.parse(tsStr.replace(' ', 'T')) : NaN; + const ts = isNaN(tsParsed) ? undefined : tsParsed; + return { hoster, fileName, ts }; + } + + const api = { formatUploadLogLine, parseUploadLogLine }; + if (typeof module !== 'undefined' && module.exports) module.exports = api; + else if (root) root.UploadLog = api; +})(typeof window !== 'undefined' ? window : this); diff --git a/main.js b/main.js index e3d8bcc..81a42ce 100644 --- a/main.js +++ b/main.js @@ -17,6 +17,7 @@ const FolderMonitor = require('./lib/folder-monitor'); const RemoteServer = require('./lib/remote-server'); const { maybeRotateLogFile } = require('./lib/log-rotation'); const { hosterLogToFileEnabled } = require('./lib/log-policy'); +const { formatUploadLogLine, parseUploadLogLine } = require('./lib/upload-log'); const { sanitizeConfig, buildSupportBundleText } = require('./lib/support-bundle'); const { buildWebhookRequest, isAllAborted } = require('./lib/webhook-notify'); @@ -597,10 +598,7 @@ function shouldLogHosterToFile(hoster) { } function appendUploadLog(hoster, link, fileName) { - const now = new Date(); - const pad = (n) => String(n).padStart(2, '0'); - const dateStr = `${now.getFullYear()}-${pad(now.getMonth() + 1)}-${pad(now.getDate())} ${pad(now.getHours())}:${pad(now.getMinutes())}:${pad(now.getSeconds())}`; - _uploadLogBuffer.push(`${dateStr}|${hoster}|${link}||${fileName}|\n`); + _uploadLogBuffer.push(formatUploadLogLine(new Date(), hoster, link, fileName)); if (!_uploadLogFlushTimer) { _uploadLogFlushTimer = setTimeout(() => { _uploadLogFlushTimer = null; @@ -1174,6 +1172,7 @@ app.whenReady().then(() => { verbose: _logVerbose, pid: process.pid }); + _sweepOrphanConfigTmps(); createWindow(); createTray(); @@ -2154,14 +2153,8 @@ ipcMain.handle('read-own-upload-log', () => { try { const content = fs.readFileSync(logPath, 'utf-8'); for (const line of content.split('\n')) { - const trimmed = line.trim(); - if (!trimmed || trimmed.startsWith('#')) continue; - const parts = trimmed.split('|'); - if (parts.length >= 5) { - const hoster = (parts[1] || '').trim(); - const fileName = (parts[4] || '').trim(); - if (hoster && fileName) entries.push({ hoster, fileName }); - } + const parsed = parseUploadLogLine(line); + if (parsed) entries.push(parsed); } } catch {} } @@ -2258,17 +2251,45 @@ ipcMain.handle('save-global-settings', async (_event, globalSettings) => { return true; }); +function _sleepSyncMs(ms) { + try { + Atomics.wait(new Int32Array(new SharedArrayBuffer(4)), 0, 0, ms); + } catch { + const end = Date.now() + ms; + while (Date.now() < end) { /* spin */ } + } +} + +function _sweepOrphanConfigTmps() { + try { + const dir = path.dirname(configStore.filePath); + const prefix = path.basename(configStore.filePath) + '.'; + const suffix = '.tmp'; + for (const file of fs.readdirSync(dir)) { + if (!file.startsWith(prefix) || !file.endsWith(suffix)) continue; + const mid = file.slice(prefix.length, file.length - suffix.length); + if (!/^\d+$/.test(mid)) continue; + const pid = Number(mid); + if (pid === process.pid) continue; + let alive = false; + try { process.kill(pid, 0); alive = true; } catch (e) { alive = !!(e && e.code === 'EPERM'); } + if (alive) continue; + try { fs.unlinkSync(path.join(dir, file)); } catch {} + } + } catch {} +} + // Synchronous save for beforeunload — blocks renderer until write completes // Uses atomic write pattern (tmp + backup + rename) to prevent corruption. // Returns false on any failure so the renderer (which surfaces this via the // beforeunload chain) doesn't quietly think queue + settings persisted when // they didn't. Errors are logged for diagnostics regardless. ipcMain.on('save-global-settings-sync', (event, globalSettings) => { + const tmpPath = configStore.filePath + '.' + process.pid + '.tmp'; try { const current = configStore.load(); current.globalSettings = globalSettings; const data = configStore._serializeForDisk(current); - const tmpPath = configStore.filePath + '.tmp'; const backupPath = configStore.filePath + '.bak'; fs.writeFileSync(tmpPath, data, 'utf-8'); if (fs.existsSync(configStore.filePath)) { @@ -2284,9 +2305,26 @@ ipcMain.on('save-global-settings-sync', (event, globalSettings) => { debugLog(`save-global-settings-sync: backup read/write skipped: ${bakErr.message}`); } } - fs.renameSync(tmpPath, configStore.filePath); + let renamed = false; + let lastErr = null; + for (let attempt = 0; attempt < 5 && !renamed; attempt++) { + try { + fs.renameSync(tmpPath, configStore.filePath); + renamed = true; + } catch (renameErr) { + lastErr = renameErr; + const code = renameErr && renameErr.code; + if (code === 'EBUSY' || code === 'EPERM' || code === 'EACCES') { + _sleepSyncMs(40); + } else { + throw renameErr; + } + } + } + if (!renamed) throw lastErr || new Error('renameSync failed'); event.returnValue = true; } catch (err) { + try { if (fs.existsSync(tmpPath)) fs.unlinkSync(tmpPath); } catch {} debugLog(`save-global-settings-sync FAILED: ${err && err.message ? err.message : err}`); event.returnValue = false; } diff --git a/renderer/app.js b/renderer/app.js index 8f13ad3..d126891 100644 --- a/renderer/app.js +++ b/renderer/app.js @@ -21,7 +21,32 @@ let healthCheckRunning = false; let accountStatuses = {}; // { accountId: { status: 'ok'|'warn'|'error'|'checking'|'unchecked', message: '' } } let editingAccountId = null; // null = adding, string = editing account by ID let autoHealthCheckEnabled = true; -let queuePersistTimer = null; +const queuePersistThrottle = (window.ThrottleTimer && window.ThrottleTimer.makeThrottleTimer) + ? window.ThrottleTimer.makeThrottleTimer() + : (function () { + let h = null; + let fn = null; + let burstStart = null; + function go() { h = null; burstStart = null; const g = fn; fn = null; if (g) g(); } + return { + request(f, d, maxWait) { + if (typeof f === 'function') fn = f; + const t = Date.now(); + if (burstStart === null) burstStart = t; + let wait = typeof d === 'number' && d >= 0 ? d : 0; + if (typeof maxWait === 'number' && maxWait >= 0) { + const remaining = maxWait - (t - burstStart); + wait = Math.min(wait, remaining < 0 ? 0 : remaining); + } + clearTimeout(h); + h = setTimeout(go, wait); + }, + flushSync() { clearTimeout(h); h = null; burstStart = null; const g = fn; fn = null; if (g) g(); }, + cancel() { clearTimeout(h); h = null; burstStart = null; fn = null; }, + isPending() { return h !== null; } + }; + })(); +let _restoredSnapshotSavedAt = null; let settingsSaveTimer = null; let lastUploadStats = { state: 'idle', globalSpeedKbs: 0, totalBytes: 0, elapsed: 0, activeJobs: 0 }; const AUTO_CHECK_PREF_KEY = 'autoHealthCheckBeforeUpload'; @@ -684,6 +709,10 @@ function restoreQueueStateFromConfig() { const pending = config?.globalSettings?.pendingQueue; if (!pending || typeof pending !== 'object') return; + _restoredSnapshotSavedAt = (typeof pending.savedAt === 'number' && isFinite(pending.savedAt)) + ? pending.savedAt + : null; + selectedUploadHosters = Array.isArray(pending.selectedUploadHosters) ? pending.selectedUploadHosters.filter(Boolean) : selectedUploadHosters; @@ -757,6 +786,7 @@ function buildPersistedQueueState() { // Only true terminal states (done / error / skipped) survive as-is. const TERMINAL = new Set(['done', 'error', 'skipped']); return { + savedAt: Date.now(), selectedUploadHosters: getSelectedHosters(), selectedFiles: Array.from(selectedFileMap.values()), queueJobs: queueJobs.map(job => { @@ -786,21 +816,19 @@ async function persistQueueStateNow() { } function persistQueueStateSoon(immediate) { - clearTimeout(queuePersistTimer); if (immediate) { + queuePersistThrottle.cancel(); persistQueueStateNow().catch(() => {}); return; } - // Use longer debounce during uploads to reduce disk I/O - const delay = uploading ? 10000 : 500; - queuePersistTimer = setTimeout(() => { + const maxWait = uploading ? 20000 : undefined; + queuePersistThrottle.request(() => { persistQueueStateNow().catch(() => {}); - }, delay); + }, 500, maxWait); } function clearPersistedQueueStateSoon() { - clearTimeout(queuePersistTimer); - queuePersistTimer = setTimeout(() => { + queuePersistThrottle.request(() => { const globalSettings = { ...(config.globalSettings || {}), pendingQueue: null @@ -4609,8 +4637,7 @@ window.addEventListener('beforeunload', () => { settingsSaveTimer = null; try { saveSettings(); } catch {} } - clearTimeout(queuePersistTimer); - queuePersistTimer = null; + queuePersistThrottle.cancel(); // Drain pending done-removals synchronously before persisting so jobs the // user expected to disappear (removeFromQueueOnDone=true) don't reappear // on next launch. Microtask wouldn't run before the sync IPC below. @@ -4912,12 +4939,12 @@ async function _autoDeduplicateFromLog() { try { const entries = await window.api.readOwnUploadLog(); if (!entries || entries.length === 0) return; - // Only 'done' jobs are dropped here (declutter completed uploads). Pending - // and failed jobs survive even if their name+hoster is in the log — they're - // intentional queued work. Decision lives in lib/queue-dedup.js (Node-tested, - // see tests/queue-dedup.test.js) so it can't silently regress to nuking the - // whole restored queue on restart/update. - const { kept, removed } = window.QueueDedup.partitionRestoredJobsByLog(queueJobs, entries); + // Drops 'done' jobs present in the log (declutter) AND any job that the log + // shows completed at/after the snapshot's savedAt (a stale 'preview' ghost). + // Pending jobs matching only OLDER log lines survive — intentional re-uploads. + // Decision lives in lib/queue-dedup.js (Node-tested, see tests/queue-dedup.test.js) + // so it can't silently regress to nuking the whole restored queue on restart. + const { kept, removed } = window.QueueDedup.partitionRestoredJobsByLog(queueJobs, entries, _restoredSnapshotSavedAt); if (removed.length > 0) { queueJobs = kept; for (const job of removed) { diff --git a/renderer/index.html b/renderer/index.html index e824b25..15b1a93 100644 --- a/renderer/index.html +++ b/renderer/index.html @@ -420,6 +420,7 @@ + diff --git a/tasks/todo.md b/tasks/todo.md index a4bf887..fa5a923 100644 --- a/tasks/todo.md +++ b/tasks/todo.md @@ -1,22 +1,58 @@ -# Feature: Per-Hoster Toggle "Links in fileuploader.log schreiben" +# Queue-Persistenz Bug: fertige Dateien tauchen nach Neustart wieder auf -## Goal -Pro Hoster ein-/ausschaltbar machen ob dessen erfolgreiche Upload-Links in die fileuploader.log geschrieben werden. +## Symptom +User: 300 Dateien, 100 übrig, Programm schließen + öffnen → manchmal sind bereits +fertig hochgeladene Dateien wieder in der Liste. -## Plan -- [x] `lib/config-store.js` — `logToFile: true` zu `HOSTER_SETTINGS_DEFAULTS` (default an). -- [x] `renderer/app.js renderSettings` — Checkbox "Links in Log schreiben" pro Hoster-Panel (`data-hs="logToFile"`, type=checkbox). -- [x] `renderer/app.js saveSettings` — collection-loop erweitert: checkbox → boolean. -- [x] `lib/log-policy.js` (neu, testbar) — `hosterLogToFileEnabled(hosterSettings, hoster)`, opt-out semantics. -- [x] `main.js` — `shouldLogHosterToFile(hoster)` liest live uploadManager.hosterSettings, fallback configStore, dann default true. Guard vor appendUploadLog im done-handler. -- [x] Tests: 8 log-policy + 2 config-store (default true, persist false). 147/147 grün. -- [x] ESLint clean. Backup-Import robust (default-true bei fehlendem key). +## Root Cause (verifiziert im Code) +- **RC-1 (Persist-Starvation, code-confirmed):** `persistQueueStateSoon()` setzt bei + jedem Progress-Event den Timer per `clearTimeout` zurück; Delay während Upload war + 10000ms. Progress-Events feuern öfter als alle 10s → Timer feuert NIE während eines + aktiven Uploads. Der Disk-Snapshot bleibt auf dem Stand VOR Upload-Start stehen + (alle Jobs `preview`). +- **RC-2 (unzuverlässiger Close-Flush):** beforeunload-Sync-Flush existiert + (app.js:4605) und fängt den sauberen Close ab. Bei hartem Kill / Crash / OS-Kill + läuft er nicht → der stale Snapshot bleibt liegen. +- **RC-3 (Dedup-Asymmetrie):** `_autoDeduplicateFromLog` droppt beim Start nur Jobs + mit Status `done`. Die Ghosts aus dem stale Snapshot stehen aber als `preview` da + → werden NICHT gedroppt → fertige Dateien erscheinen erneut. -## Verifikation -- logToFile default true → bestehendes Verhalten unverändert für alle die's nicht togglen. -- Toggle off für Hoster X → uploads von X werden NICHT geloggt, andere Hoster weiter schon. -- Live-Wirkung: `uploadManager.hosterSettings` wird via updateSettings aktualisiert → greift auch mid-batch nach save. +## Fix (mechanismus-unabhängig, vom Kern auf) +- [x] **FIX A — Timestamp-gated Dedup (Kern-Fix, durable):** Beim Start jeden restored + Job droppen, dessen file+hoster im Log mit `ts >= floor(savedAt)` steht — egal ob + `preview` oder `done`. Fängt Ghosts auch nach hartem Kill (hängt vom Log ab, nicht + vom Snapshot). `lib/queue-dedup.js` additiver 3. Param `savedAt`; `buildPersistedQueueState` + stempelt `savedAt`; `restoreQueueStateFromConfig` merkt `_restoredSnapshotSavedAt`; + Log-Zeile → `ts` geparst; `_autoDeduplicateFromLog` reicht savedAt durch. +- [x] **FIX B — Throttle mit max-wait:** `lib/throttle-timer.js` (neu). Upload: delay 500 + + maxWait 20000 → Snapshot alle ~20s statt nie. Idle: reine Debounce. Fallback-Shim + honoriert maxWait (kein stilles Starvation-Reintro). +- [x] **FIX C — Close-Write-Härtung:** `save-global-settings-sync` renameSync-Retry bei + EBUSY/EPERM/EACCES + pid-unique tmp + tmp-cleanup. Startup-Sweep `_sweepOrphanConfigTmps` + räumt verwaiste `..tmp` toter PIDs (gegen Orphan-Akkumulation). +- [x] **Seam-Extraktion (Advisor #2):** `lib/upload-log.js` (neu) — `formatUploadLogLine` + + `parseUploadLogLine` aus main.js gezogen; Test fährt den ECHTEN Writer→Reader→Gate- + Vertrag (kein Mirror) → fängt künftige Format-/Epoch-Brüche. -## Seiteneffekte zu prüfen -- Backup-Import/Export: hosterSettings inkl. logToFile mitnehmen (sollte automatisch da generisches Objekt). -- Settings-autosave (checkbox change-event ist bereits gehandhabt in der bind-loop). +## Tests +- [x] `tests/throttle-timer.test.js`: Starvation ohne maxWait → 0 Fires; mit maxWait → + periodische Fires; last-write-wins (distinct fn); flushSync/cancel. +- [x] `tests/queue-dedup.test.js`: ts>=savedAt→DROP; ts { const jobs = [job('done', 'x.mkv', 'voe.sx')]; assert.equal(partitionRestoredJobsByLog(jobs, undefined).kept.length, 1); }); + +const T = (s) => Date.parse(s.replace(' ', 'T')); + +test('ts-gate: preview job uploaded AFTER the snapshot is dropped (the ghost bug)', () => { + const jobs = [job('preview', 'a.mkv', 'voe.sx')]; + const log = [{ fileName: 'a.mkv', hoster: 'voe.sx', ts: T('2026-06-19 12:00:05') }]; + const savedAt = T('2026-06-19 12:00:00'); + const { kept, removed } = partitionRestoredJobsByLog(jobs, log, savedAt); + assert.equal(removed.length, 1, 'completed-after-snapshot preview is a ghost → drop'); + assert.equal(kept.length, 0); +}); + +test('ts-gate: preview job whose only log entry PREDATES the snapshot is kept (intentional re-upload)', () => { + const jobs = [job('preview', 'a.mkv', 'voe.sx')]; + const log = [{ fileName: 'a.mkv', hoster: 'voe.sx', ts: T('2026-06-19 11:00:00') }]; + const savedAt = T('2026-06-19 12:00:00'); + const { kept, removed } = partitionRestoredJobsByLog(jobs, log, savedAt); + assert.equal(removed.length, 0, 'old upload + freshly-queued re-upload must survive'); + assert.equal(kept.length, 1); +}); + +test('ts-gate: same-second completion is dropped (savedAt floored to the second)', () => { + const jobs = [job('preview', 'a.mkv', 'voe.sx')]; + const log = [{ fileName: 'a.mkv', hoster: 'voe.sx', ts: T('2026-06-19 12:00:00') }]; + const savedAt = T('2026-06-19 12:00:00') + 800; + const { removed } = partitionRestoredJobsByLog(jobs, log, savedAt); + assert.equal(removed.length, 1, 'log second-granularity must not let same-second ghosts slip through'); +}); + +test('ts-gate: uses the MAX log ts per key (re-upload after a stale earlier entry)', () => { + const jobs = [job('preview', 'a.mkv', 'voe.sx')]; + const log = [ + { fileName: 'a.mkv', hoster: 'voe.sx', ts: T('2026-06-19 11:00:00') }, + { fileName: 'a.mkv', hoster: 'voe.sx', ts: T('2026-06-19 12:00:05') } + ]; + const savedAt = T('2026-06-19 12:00:00'); + const { removed } = partitionRestoredJobsByLog(jobs, log, savedAt); + assert.equal(removed.length, 1, 'newest matching log entry decides'); +}); + +test('ts-gate inactive without savedAt → legacy behavior (preview kept even if ts newer)', () => { + const jobs = [job('preview', 'a.mkv', 'voe.sx')]; + const log = [{ fileName: 'a.mkv', hoster: 'voe.sx', ts: T('2026-06-19 12:00:05') }]; + const { kept, removed } = partitionRestoredJobsByLog(jobs, log); + assert.equal(removed.length, 0); + assert.equal(kept.length, 1); +}); + +test('ts-gate inactive when log entry lacks ts → legacy behavior', () => { + const jobs = [job('preview', 'a.mkv', 'voe.sx')]; + const log = [{ fileName: 'a.mkv', hoster: 'voe.sx' }]; + const savedAt = T('2026-06-19 12:00:00'); + const { kept, removed } = partitionRestoredJobsByLog(jobs, log, savedAt); + assert.equal(removed.length, 0); + assert.equal(kept.length, 1); +}); + +test('ts-gate: done job uploaded after snapshot is dropped via either rule', () => { + const jobs = [job('done', 'a.mkv', 'voe.sx')]; + const log = [{ fileName: 'a.mkv', hoster: 'voe.sx', ts: T('2026-06-19 12:00:05') }]; + const savedAt = T('2026-06-19 12:00:00'); + const { removed } = partitionRestoredJobsByLog(jobs, log, savedAt); + assert.equal(removed.length, 1); +}); + +test('ts-gate: multi-hoster partial completion — the reported bug shape (drop only the completed hosters)', () => { + // One file queued to 4 hosters; close mid-upload. After the snapshot, 2 hosters + // completed (logged), 2 never started. On restart all 4 restore as 'preview'. + // Must drop EXACTLY the 2 that completed and keep the 2 still-pending. This also + // pins per-hoster keying: a fileName-only gate would wrongly drop all 4. + const f = 'Einfach mal die Fresse halten!!!.mp4'; + const jobs = [ + job('preview', f, 'doodstream.com'), + job('preview', f, 'voe.sx'), + job('preview', f, 'vidmoly.me'), + job('preview', f, 'byse.sx') + ]; + const savedAt = T('2026-06-19 12:00:00'); + const log = [ + { fileName: f, hoster: 'doodstream.com', ts: T('2026-06-19 12:00:08') }, + { fileName: f, hoster: 'voe.sx', ts: T('2026-06-19 12:00:11') } + ]; + const { kept, removed } = partitionRestoredJobsByLog(jobs, log, savedAt); + assert.equal(removed.length, 2, 'only the 2 completed-after-snapshot hosters drop'); + assert.ok(removed.every(j => j.hoster === 'doodstream.com' || j.hoster === 'voe.sx')); + assert.equal(kept.length, 2, 'the 2 never-started hosters survive'); + assert.ok(kept.some(j => j.hoster === 'vidmoly.me')); + assert.ok(kept.some(j => j.hoster === 'byse.sx')); +}); diff --git a/tests/throttle-timer.test.js b/tests/throttle-timer.test.js new file mode 100644 index 0000000..4ad4c82 --- /dev/null +++ b/tests/throttle-timer.test.js @@ -0,0 +1,133 @@ +const { test } = require('node:test'); +const assert = require('node:assert'); +const { makeThrottleTimer } = require('../lib/throttle-timer'); + +function fakeClock() { + let t = 0; + let timers = []; + return { + now: () => t, + schedule: (cb, ms) => { + const h = { at: t + ms, cb, dead: false }; + timers.push(h); + return h; + }, + clear: (h) => { if (h) h.dead = true; }, + advance: (ms) => { + const target = t + ms; + for (;;) { + let next = null; + for (const h of timers) { + if (!h.dead && h.at <= target && (next === null || h.at < next.at)) next = h; + } + if (!next) break; + t = next.at; + next.dead = true; + next.cb(); + } + t = target; + timers = timers.filter(h => !h.dead); + } + }; +} + +test('idle debounce: fires once after the delay window', () => { + const c = fakeClock(); + const tt = makeThrottleTimer(c); + let fired = 0; + tt.request(() => fired++, 500); + c.advance(499); + assert.equal(fired, 0); + c.advance(1); + assert.equal(fired, 1); +}); + +test('idle debounce: rapid requests reset the timer (last wins)', () => { + const c = fakeClock(); + const tt = makeThrottleTimer(c); + let fired = 0; + tt.request(() => fired++, 500); + c.advance(200); + tt.request(() => fired++, 500); + c.advance(300); + assert.equal(fired, 0, 'should not fire at original 500 — was reset'); + c.advance(200); + assert.equal(fired, 1, 'fires 500ms after the second request'); +}); + +test('STARVATION repro: continuous requests with no maxWait NEVER fire', () => { + const c = fakeClock(); + const tt = makeThrottleTimer(c); + let fired = 0; + for (let i = 0; i < 30; i++) { + tt.request(() => fired++, 500); + c.advance(100); + } + assert.equal(fired, 0, 'this is exactly the bug the maxWait fix addresses'); +}); + +test('maxWait: continuous requests still force a fire within the window', () => { + const c = fakeClock(); + const tt = makeThrottleTimer(c); + let fired = 0; + const fireAtTimes = []; + for (let i = 0; i < 30; i++) { + tt.request(() => { fired++; fireAtTimes.push(c.now()); }, 500, 2000); + c.advance(100); + } + assert.ok(fired >= 1, 'maxWait guarantees at least one fire under continuous load'); + assert.ok(fireAtTimes.every(t => t > 0), 'fires happened, not starved'); + assert.ok(fireAtTimes.some(t => t <= 2000), 'first fire no later than maxWait'); +}); + +test('maxWait: after a forced fire a fresh burst starts (periodic fires)', () => { + const c = fakeClock(); + const tt = makeThrottleTimer(c); + let fired = 0; + for (let i = 0; i < 60; i++) { + tt.request(() => fired++, 500, 2000); + c.advance(100); + } + assert.ok(fired >= 2, `~6000ms of continuous load with 2000ms maxWait should fire multiple times, got ${fired}`); +}); + +test('flushSync fires the pending fn immediately and clears it', () => { + const c = fakeClock(); + const tt = makeThrottleTimer(c); + let fired = 0; + tt.request(() => fired++, 5000); + assert.ok(tt.isPending()); + tt.flushSync(); + assert.equal(fired, 1); + assert.ok(!tt.isPending()); + c.advance(10000); + assert.equal(fired, 1, 'no double fire after flushSync'); +}); + +test('cancel drops the pending fn — no fire', () => { + const c = fakeClock(); + const tt = makeThrottleTimer(c); + let fired = 0; + tt.request(() => fired++, 500); + tt.cancel(); + assert.ok(!tt.isPending()); + c.advance(10000); + assert.equal(fired, 0); +}); + +test('last-write-wins: a later request with a DIFFERENT fn replaces the earlier one', () => { + const c = fakeClock(); + const tt = makeThrottleTimer(c); + const fired = []; + tt.request(() => fired.push('persist'), 500, 20000); + c.advance(100); + tt.request(() => fired.push('clear'), 0); + c.advance(100); + assert.deepEqual(fired, ['clear'], 'only the latest fn fires; the persist was dropped'); +}); + +test('flushSync with nothing pending is a no-op', () => { + const c = fakeClock(); + const tt = makeThrottleTimer(c); + assert.doesNotThrow(() => tt.flushSync()); +}); diff --git a/tests/upload-log.test.js b/tests/upload-log.test.js new file mode 100644 index 0000000..ce21225 --- /dev/null +++ b/tests/upload-log.test.js @@ -0,0 +1,52 @@ +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); +});