diff --git a/.gitignore b/.gitignore index 52e305a..d2766e6 100644 --- a/.gitignore +++ b/.gitignore @@ -6,7 +6,10 @@ __pycache__/ electron-config.json electron-config.json.bak electron-config.json.tmp +electron-config.json.pre-history-split.bak electron-config.pre-import-*.json +electron-history.json +electron-history.json.tmp *.log debug.log fileuploader.log diff --git a/lib/config-store.js b/lib/config-store.js index 9b81c8b..f58bc13 100644 --- a/lib/config-store.js +++ b/lib/config-store.js @@ -184,15 +184,87 @@ class ConfigStore { ? app.getPath('userData') : path.join(__dirname, '..'); this.filePath = path.join(dir, 'electron-config.json'); + this.historyPath = path.join(dir, 'electron-history.json'); this._writeQueue = Promise.resolve(); // Serializes all writes to prevent race conditions + this._historyWriteQueue = Promise.resolve(); + this._historyMigrated = false; this._cache = null; this._cacheKey = ''; this._perfLog = null; + this._wqDepth = 0; // Migrate config from old location if current doesn't exist if (!fs.existsSync(this.filePath) && app && app.isPackaged) { this._migrateFromOldPath(app); } + if (app && app.isPackaged) { + this._migrateHistory(); + } + } + + _readHistoryFile() { + try { + const raw = fs.readFileSync(this.historyPath, 'utf-8'); + if (!raw || raw.trim().length < 2) return []; + const parsed = JSON.parse(raw); + if (Array.isArray(parsed)) return parsed; + if (parsed && Array.isArray(parsed.history)) return parsed.history; + return []; + } catch { + return null; + } + } + + _writeHistoryFileDurable(arr) { + const tmp = this.historyPath + '.tmp'; + const fd = fs.openSync(tmp, 'w'); + try { + fs.writeSync(fd, JSON.stringify(arr)); + fs.fsyncSync(fd); + } finally { + fs.closeSync(fd); + } + fs.renameSync(tmp, this.historyPath); + } + + _writeHistoryFileAtomic(arr) { + return new Promise((resolve, reject) => { + const tmp = this.historyPath + '.tmp'; + fs.writeFile(tmp, JSON.stringify(arr), 'utf-8', (err) => { + if (err) return reject(err); + try { fs.renameSync(tmp, this.historyPath); } catch (e) { return reject(e); } + resolve(); + }); + }); + } + + _enqueueHistoryWrite(fn) { + this._historyWriteQueue = this._historyWriteQueue.then(fn, fn); + return this._historyWriteQueue; + } + + _migrateHistory() { + try { + if (fs.existsSync(this.historyPath)) { + this._historyMigrated = Array.isArray(this._readHistoryFile()); + return; + } + let cfg = null; + try { cfg = this._readAndParse(this.filePath); } catch {} + const hist = (cfg && Array.isArray(cfg.history)) ? cfg.history : []; + this._writeHistoryFileDurable(hist); + const check = this._readHistoryFile(); + if (Array.isArray(check) && check.length === hist.length) { + if (hist.length > 0) { + try { fs.copyFileSync(this.filePath, this.filePath + '.pre-history-split.bak'); } catch {} + } + this._historyMigrated = true; + } else { + this._historyMigrated = false; + } + } catch { + this._historyMigrated = false; + } } _migrateFromOldPath(app) { @@ -231,6 +303,23 @@ class ConfigStore { setPerfLog(fn) { this._perfLog = typeof fn === 'function' ? fn : null; } + _pqLen(globalSettings) { + const pq = globalSettings && globalSettings.pendingQueue; + return pq && Array.isArray(pq.queueJobs) ? pq.queueJobs.length : 0; + } + + _callerTag() { + const lines = (new Error().stack || '').split('\n'); + const out = []; + for (let i = 2; i < lines.length && out.length < 3; i++) { + const line = lines[i].trim(); + if (/config-store\.js/.test(line)) continue; + const m = line.match(/at (?:async )?([^ (]+)/); + if (m) out.push(m[1].split('.').pop()); + } + return out.join('<') || '?'; + } + load() { if (!this._perfLog) return this._loadImpl(); const hadCache = !!this._cache; @@ -238,9 +327,9 @@ class ConfigStore { const r = this._loadImpl(); const dt = performance.now() - t0; if (dt >= 20) { - const q = ((r && r.globalSettings && r.globalSettings.pendingQueue) || []).length; + const q = this._pqLen(r && r.globalSettings); const h = (r && r.history || []).length; - this._perfLog(`config-load wall=${dt.toFixed(0)}ms cache=${hadCache ? 'hit' : 'miss'} hist=${h} queue=${q}`); + this._perfLog(`config-load wall=${dt.toFixed(0)}ms cache=${hadCache ? 'hit' : 'miss'} hist=${h} queue=${q} via=${this._callerTag()}`); } return r; } @@ -345,7 +434,7 @@ class ConfigStore { const rotationCursors = (data.rotationCursors && typeof data.rotationCursors === 'object' && !Array.isArray(data.rotationCursors)) ? data.rotationCursors : {}; - const result = { hosters, hosterSettings, globalSettings, history: data.history || [], rotationCursors }; + const result = { hosters, hosterSettings, globalSettings, history: this._historyMigrated ? [] : (data.history || []), rotationCursors }; // Decrypt credentials stored with safeStorage so the rest of the app // keeps working with plaintext in memory. secretStore.decryptCredentials(result); @@ -378,15 +467,17 @@ class ConfigStore { const data = this._serializeForDisk(config); const dt = performance.now() - t0; if (dt >= 20) { - const q = ((config.globalSettings && config.globalSettings.pendingQueue) || []).length; + const q = this._pqLen(config.globalSettings); const h = (config.history || []).length; - this._perfLog(`config-serialize wall=${dt.toFixed(0)}ms bytes=${data.length} hist=${h} queue=${q}`); + this._perfLog(`config-serialize wall=${dt.toFixed(0)}ms bytes=${data.length} hist=${h} queue=${q} wqDepth=${this._wqDepth} via=${this._callerTag()}`); } return this._atomicWrite(data); } _enqueueWrite(fn) { - this._writeQueue = this._writeQueue.then(fn, fn); + this._wqDepth++; + const done = () => { this._wqDepth--; }; + this._writeQueue = this._writeQueue.then(fn, fn).then(done, done); return this._writeQueue; } @@ -401,6 +492,9 @@ class ConfigStore { } loadHistory() { + if (this._historyMigrated) { + return this._readHistoryFile() || []; + } const config = this.load(); return config.history || []; } @@ -436,6 +530,18 @@ class ConfigStore { } appendHistory(entry) { + if (this._historyMigrated) { + return this._enqueueHistoryWrite(() => { + const cur = this._readHistoryFile(); + if (cur === null && fs.existsSync(this.historyPath)) return; + const arr = cur || []; + arr.push(entry); + const gs = this.load().globalSettings; + const retention = (gs && gs.historyRetention) || 'all'; + const pruned = applyHistoryRetention(arr, retention, Date.now()); + return this._writeHistoryFileAtomic(pruned); + }); + } return this._enqueueWrite(() => { const config = this.load(); config.history.push(entry); @@ -447,6 +553,24 @@ class ConfigStore { pruneHistory(retention, opts = {}) { const dryRun = !!opts.dryRun; + if (this._historyMigrated) { + return this._enqueueHistoryWrite(() => { + const current = this._readHistoryFile() || []; + const beforeBatches = current.length; + const beforeRows = countHistoryRows(current); + const pruned = applyHistoryRetention(current, retention, Date.now()); + const result = { + removedBatches: beforeBatches - pruned.length, + removedRows: beforeRows - countHistoryRows(pruned), + keptBatches: pruned.length, + keptRows: countHistoryRows(pruned) + }; + if (dryRun) return result; + return this._writeHistoryFileAtomic(pruned) + .then(() => this.save({ globalSettings: { ...this.load().globalSettings, historyRetention: String(retention || 'all') } })) + .then(() => result); + }); + } return this._enqueueWrite(() => { const config = this.load(); const beforeBatches = config.history.length; @@ -466,6 +590,9 @@ class ConfigStore { } clearHistory() { + if (this._historyMigrated) { + return this._enqueueHistoryWrite(() => this._writeHistoryFileAtomic([])); + } return this._enqueueWrite(() => { const config = this.load(); config.history = []; diff --git a/main.js b/main.js index b844a85..cabb3fe 100644 --- a/main.js +++ b/main.js @@ -46,6 +46,47 @@ try { _gcObserver.observe({ entryTypes: ['gc'] }); } catch {} +const _perfOn = process.env.MHU_PERF !== '0'; +let _lastIpcChannel = ''; +if (_perfOn) { + let _driftTick = Date.now(); + setInterval(() => { + const now = Date.now(); + const drift = now - _driftTick - 100; + _driftTick = now; + if (drift >= 100) { + try { logInfo(`main-longtask blocked=${drift}ms lastIpc=${_lastIpcChannel || '-'} gc=${_gcCount} gcMax=${_gcMaxMs.toFixed(0)}ms`); } catch {} + } + }, 100).unref(); + + const IPC_SLOW_MS = 50; + const _ipcLog = (m) => { try { logInfo(m); } catch {} }; + const _rawHandle = ipcMain.handle.bind(ipcMain); + ipcMain.handle = (channel, fn) => _rawHandle(channel, function (evt, ...args) { + _lastIpcChannel = channel; + const t0 = performance.now(); + let p; + try { p = fn.call(this, evt, ...args); } + catch (e) { _ipcLog(`ipc ${channel} sync-throw wall=${(performance.now() - t0).toFixed(0)}ms`); throw e; } + const sync = performance.now() - t0; + if (p && typeof p.then === 'function') { + return Promise.resolve(p).finally(() => { + const total = performance.now() - t0; + if (total >= IPC_SLOW_MS) _ipcLog(`ipc ${channel} wall=${total.toFixed(0)}ms sync=${sync.toFixed(0)}ms`); + }); + } + if (sync >= IPC_SLOW_MS) _ipcLog(`ipc ${channel} wall=${sync.toFixed(0)}ms sync`); + return p; + }); + const _rawOn = ipcMain.on.bind(ipcMain); + ipcMain.on = (channel, fn) => _rawOn(channel, function (evt, ...args) { + _lastIpcChannel = channel; + const t0 = performance.now(); + try { return fn.call(this, evt, ...args); } + finally { const dt = performance.now() - t0; if (dt >= IPC_SLOW_MS) _ipcLog(`ipc ${channel} wall=${dt.toFixed(0)}ms sync-on`); } + }); +} + let mainWindow; let _lastImportPath = null; let dropTargetWindow = null; diff --git a/package.json b/package.json index efe1356..fa4f021 100644 --- a/package.json +++ b/package.json @@ -1,6 +1,6 @@ { "name": "multi-hoster-uploader", - "version": "3.3.98", + "version": "3.3.99", "description": "Upload files to doodstream, voe, vidmoly, byse simultaneously", "main": "main.js", "scripts": { diff --git a/tasks/lessons.md b/tasks/lessons.md index ac82809..e270bfb 100644 --- a/tasks/lessons.md +++ b/tasks/lessons.md @@ -1,5 +1,37 @@ # Lessons +## 2026-06-21 — Das eigene Instrument lügt nicht, aber sein Log-Code kann buggen (`queue=undefined`) +**Symptom:** Drei Builds lang jagte ich Read-Bursts (highWaterMark, threadpool), während der WAHRE Treiber +eine 38,5-MB-electron-config.json war, die 137×/73s geklont/geparst/serialisiert wurde (~47% Main-Thread). +Erst das in v3.3.98 eingebaute `config-load/config-serialize`-Log machte es sichtbar — aber mein eigenes +Log-Feld `queue=` las `.length` auf dem pendingQueue-OBJEKT (immer undefined) und hätte mich fast in die +falsche Richtung (pendingQueue statt history) geschickt. +**Root cause:** (1) Ich hatte die config-Persistenz als „instrumentieren, nicht fixen" zurückgestellt (richtig +für die unsichere Migration), aber den Lag-Treiber dort nicht früh genug vermutet. (2) Instrument-Felder selbst +müssen verifiziert werden: `(obj || []).length` auf einem Objekt = undefined, still falsch. +**Regel:** Wenn der User „es laggt unverändert" sagt obwohl die letzte Messung gut aussah, ist der gemessene +Pfad NICHT der Hot-Path — sofort BREITER messen (jeden IPC-Handler, jede periodische Main-Op, Main-Thread- +Longtask-Monitor), nicht den schon-gemessenen Pfad weiter optimieren. Und Instrument-Ausgaben gegen ein +bekanntes Beispiel prüfen (zeigt `queue=` je eine echte Zahl?). +**Wie anwenden:** Bei „Symptom unverändert trotz Fix": Hypothese fallen lassen, Coverage verbreitern. Log-Felder +beim Schreiben mit einem realen Wert gegenchecken, nie blind `(x||[]).length` auf unklar getypten Feldern. + +## 2026-06-21 — „Brot finden, nicht Krümel": die EINE Änderung, die alle Kosten killt, schlägt drei sichere Teilfixes +**Symptom:** Fix-Design bot loadShallow (Klon vermeiden) + cache-repopulate + resolution-cache. Adversary zeigte: +loadShallow killt nur den Klon (~10s von 34s), die 38 Serializes (8,4s) + 38 Post-Write-Reparses (15,2s) bleiben, +weil Writes den Cache nullen → loadShallow allein = Krümel. +**Root cause:** Alle drei Kosten (parse+clone+serialize) entstehen daraus, dass history IM Hot-Config liegt. +Nur history RAUS aus der immer-geladenen Datei (eigene electron-history.json) killt alle drei gleichzeitig. +cache-repopulate-Gate feuerte nie (toter Code); resolution-cache hätte stale-Pools → Failover-Regression +(rotation/byse) riskiert = die EINE Sache die Uploads STILL korrumpiert, schlimmer als Lag. +**Regel:** Wenn der User „komplett wegmachen" fordert und mehrere sichere Teilfixes vs. ein riskanterer +Komplettfix zur Wahl stehen: den Komplettfix nehmen, aber RICHTIG absichern (hier: fsync+verify-before-strip, +permanenter .pre-history-split.bak, Migration packaged-only + per-Init nicht in load(), Crash-Window-Fallback, +Test gegen die ECHTE 194MB-Fixture). Teilfixes die den Treiber nur anknabbern NICHT bündeln (verwässert Messung ++ Risiko). Einen Fix der etwas STILL korrumpieren könnte (stale Account-Pools) NIE für Performance einbauen. +**Wie anwenden:** Bei mehreren Fix-Optionen fragen: „welche EINE Änderung entfernt die gemeinsame Wurzel ALLER +Kostenpfade?" — die nehmen und maximal absichern, statt N sichere Teilfixes die je nur einen Pfad treffen. + ## 2026-06-21 — Ein-Variablen-Disziplin: nicht zwei Fixes bündeln, wenn einer den anderen maskiert **Symptom:** Nach dem tp=8-Win wollte ich in EINEM Build A (1MB highWaterMark, Read-Burst) + B (Renderer chunked rAF Batch-Drain, der 243ms-Longtask) + C-Instrument shippen. diff --git a/tasks/todo.md b/tasks/todo.md index de67d9d..8e85c7c 100644 --- a/tasks/todo.md +++ b/tasks/todo.md @@ -1,3 +1,48 @@ +# v3.3.99 — THE KILL: 38.5MB config-thrash → history split out of the hot config + full instrumentation + +THE ROOT CAUSE (from v3.3.98's instrument, the real "bread"): electron-config.json was **38.5MB** and got +loaded/cloned/serialized **137× in 73s** on the main thread (140-592ms each) = **~47% main-thread occupancy** +→ that IS the 1-2s button lag. The 1MB read-ahead was irrelevant against it. NOT the queue (`queue=undefined` +was a LOGGING BUG: read `.length` on the pendingQueue OBJECT); the bulk is HISTORY — each batch-done appended +the full per-file result list (`summary.files` w/ per-hoster URLs), 75 batches, default historyRetention='all' +never prunes → unbounded. (5-agent workflow wz2g4bwka + adversarial verify; bench fixture confirmed 185MB = +100MB history/30000 entries.) + +Why writes drove the storm: save-global-settings (queue-persist) did 2 loads + 1 serialize per call, and +_atomicWrite NULLS the cache → next load is a full 38.5MB reparse. Even cache HITS structuredCloned 38.5MB. +Per-job upload path makes ZERO config calls (selectUploadAuth/rotation take config by param) — pending=1280 +is NOT the driver. + +THE FIX (history split — kills clone AND serialize AND reparse at once; advisor-gated, adversarially verified): +- History moved to its OWN file **electron-history.json** (lib/config-store.js). _migrateHistory() runs ONCE + at init (packaged only), fail-safe: write history.json + fsync + verify count BEFORE the config is ever + allowed to drop history, keep a permanent `electron-config.json.pre-history-split.bak`. _loadImpl returns + `history:[]` when migrated → cached result is tiny → clones cheap; config file shrinks to ~KB on the first + save() → reparse cheap; _serializeForDisk writes ~KB → serialize cheap. loadHistory/appendHistory/ + pruneHistory/clearHistory redirected to history.json (own write-queue, no-clobber guard); legacy config + path kept as fallback when migration fails. get-history/export-history go through loadHistory. +- REAL 194MB-FIXTURE VALIDATION: migrate 1.5s (1×), all 30000 entries preserved + .bak; load() 631ms cold + (1×) → **0.1ms** after strip; save() strips config **185MB→2.1KB**; loadHistory() still 30000. RESULT: + data-preserved=true, hotpath-fast=true. +- DROPPED per advisor (one-variable + risk): loadShallow (moot after split), Fix#2 cache-repopulate (dead + gate), Fix#4 resolution-cache (stale-cache → rotation/byse failover-regression class — the one thing that + could SILENTLY corrupt uploads). Fix#3 (this split) was the only complete fix. + +"MEASURE EVERYTHING" instrumentation (user demand) — all additive, threshold-gated, MHU_PERF=0 to disable: +- IPC handler wrapper (monkey-patch ipcMain.handle/.on) → `ipc wall=Xms sync=Yms` ≥50ms = the + button-press→response latency, hardened so a logging throw can never break IPC (Promise.resolve(p).finally). +- Main-process long-task drift monitor (setInterval 100ms) → `main-longtask blocked=Xms lastIpc=… gc=… gcMax=…` + for any single main-thread turn >100ms (catches GC, fs scans, serialize the IPC wrapper structurally can't see). +- config-store: caller attribution `via=` + `wqDepth=` on config-load/config-serialize lines; FIXED the + `queue=` logging bug (now reads pendingQueue.queueJobs.length). + +405 tests pass (9 new migration tests covering preserve-count, round-trip, save()-never-loses-history, +crash-window fallback, idempotency). Clean Electron boot (9s, no errors). No repo pollution (migration packaged-only). +NEXT LOG must show: config-load/config-serialize wall= drop to single digits (or vanish), main-longtask rare, +ipc lines name any residual. If a residual remains it's pendingQueue (own follow-up, not a regression). + +--- + # v3.3.98 — read-burst absorption (1MB hwm) + persist/load instrument; B (renderer) DEFERRED v3.3.97 (threadpool 64→8) was a DECISIVE win: mean ELD 200ms→~11ms at 70 active (18×), renderer healthy diff --git a/tests/config-store.test.js b/tests/config-store.test.js index 809df3e..6bd9616 100644 --- a/tests/config-store.test.js +++ b/tests/config-store.test.js @@ -17,6 +17,7 @@ function createStore() { // We override by setting filePath directly store = new ConfigStore(fakeApp); store.filePath = path.join(tmpDir, 'electron-config.json'); + store.historyPath = path.join(tmpDir, 'electron-history.json'); return store; } @@ -293,3 +294,95 @@ describe('ConfigStore', () => { assert.equal(config.hosters['doodstream.com'][0].apiKey, 'from-backup'); }); }); + +describe('ConfigStore history split (electron-history.json)', () => { + let dir; + let s; + + function makeStore() { + const st = new ConfigStore({ isPackaged: false, getPath: () => dir }); + st.filePath = path.join(dir, 'electron-config.json'); + st.historyPath = path.join(dir, 'electron-history.json'); + return st; + } + + function writeConfigWithHistory(n) { + const history = []; + for (let i = 0; i < n; i++) history.push({ id: `batch-${i}`, timestamp: 1750000000000 + i, total: 3, files: [{ name: `f${i}.mkv` }] }); + fs.writeFileSync(path.join(dir, 'electron-config.json'), JSON.stringify({ + hosters: { 'byse.sx': [{ id: 'a1', authType: 'api', apiKey: 'k' }] }, + hosterSettings: {}, globalSettings: { historyRetention: 'all' }, history + }), 'utf-8'); + } + + beforeEach(() => { dir = fs.mkdtempSync(path.join(os.tmpdir(), 'cfg-hist-')); s = makeStore(); }); + afterEach(() => { fs.rmSync(dir, { recursive: true, force: true }); }); + + it('migration moves history into electron-history.json, preserving every entry', () => { + writeConfigWithHistory(50); + s._migrateHistory(); + assert.equal(s._historyMigrated, true); + assert.ok(fs.existsSync(s.historyPath)); + const hist = JSON.parse(fs.readFileSync(s.historyPath, 'utf-8')); + assert.equal(hist.length, 50); + assert.equal(hist[0].id, 'batch-0'); + assert.equal(hist[49].id, 'batch-49'); + assert.ok(fs.existsSync(s.filePath + '.pre-history-split.bak'), 'a permanent pre-split backup is kept'); + }); + + it('after migration load() excludes history (cheap hot path) but loadHistory() returns the real data', () => { + writeConfigWithHistory(30); + s._migrateHistory(); + assert.deepEqual(s.load().history, [], 'history is not carried in the always-loaded config'); + assert.equal(s.loadHistory().length, 30); + }); + + it('appendHistory writes to history.json; the next config write strips stale history from the config file', async () => { + writeConfigWithHistory(10); + s._migrateHistory(); + await s.appendHistory({ id: 'new-batch', timestamp: 1750000099999, total: 1, files: [{ name: 'x.mkv' }] }); + assert.equal(s.loadHistory().length, 11, 'append goes to history.json'); + await s.save({ globalSettings: { alwaysOnTop: true } }); + const onDisk = JSON.parse(fs.readFileSync(s.filePath, 'utf-8')); + assert.ok(!onDisk.history || onDisk.history.length === 0, 'a config write strips stale history from the config file'); + assert.equal(s.loadHistory().length, 11, 'history.json is unaffected by the config write'); + }); + + it('save({globalSettings}) after migration NEVER loses history (data-loss invariant)', async () => { + writeConfigWithHistory(40); + s._migrateHistory(); + await s.save({ globalSettings: { alwaysOnTop: true } }); + assert.equal(s.loadHistory().length, 40, 'a settings write must not touch history'); + assert.equal(s.load().globalSettings.alwaysOnTop, true); + }); + + it('clearHistory empties history.json only', async () => { + writeConfigWithHistory(20); + s._migrateHistory(); + await s.clearHistory(); + assert.equal(s.loadHistory().length, 0); + }); + + it('migration is idempotent — re-running with history.json present does not re-derive or clobber', () => { + writeConfigWithHistory(15); + s._migrateHistory(); + const after = makeStore(); + after._migrateHistory(); + assert.equal(after._historyMigrated, true); + assert.equal(after.loadHistory().length, 15); + }); + + it('crash-window fallback: not migrated + no history.json → loadHistory reads config.history', () => { + writeConfigWithHistory(7); + assert.equal(s._historyMigrated, false); + assert.equal(s.loadHistory().length, 7, 'legacy path still serves history if migration never ran'); + }); + + it('pruneHistory trims history.json and persists the retention setting', async () => { + writeConfigWithHistory(12); + s._migrateHistory(); + const res = await s.pruneHistory('all', { dryRun: false }); + assert.equal(s.loadHistory().length, 12); + assert.ok(res.keptBatches === 12); + }); +});