diff --git a/main.js b/main.js index 286bd7e..4796004 100644 --- a/main.js +++ b/main.js @@ -1,5 +1,5 @@ -process.env.UV_THREADPOOL_SIZE = process.env.UV_THREADPOOL_SIZE || '64'; -const { monitorEventLoopDelay } = require('perf_hooks'); +process.env.UV_THREADPOOL_SIZE = process.env.UV_THREADPOOL_SIZE || '8'; +const { monitorEventLoopDelay, PerformanceObserver } = require('perf_hooks'); const { app, BrowserWindow, ipcMain, dialog, clipboard, nativeTheme, Tray, Menu, nativeImage } = require('electron'); nativeTheme.themeSource = 'dark'; const path = require('path'); @@ -32,6 +32,19 @@ _eventLoopDelay.enable(); let _eldLastLog = 0; let _lastCpu = process.cpuUsage(); let _lastCpuT = Date.now(); +let _gcCount = 0; +let _gcTotalMs = 0; +let _gcMaxMs = 0; +try { + const _gcObserver = new PerformanceObserver((list) => { + for (const entry of list.getEntries()) { + _gcCount++; + _gcTotalMs += entry.duration; + if (entry.duration > _gcMaxMs) _gcMaxMs = entry.duration; + } + }); + _gcObserver.observe({ entryTypes: ['gc'] }); +} catch {} let mainWindow; let _lastImportPath = null; @@ -212,11 +225,20 @@ function _maybeLogEventLoopDelay(activeJobs) { const d = process.cpuUsage(_lastCpu); const wall = now - _lastCpuT; const pct = wall > 0 ? Math.round((d.user + d.system) / 1000 / wall * 100) : 0; - const rss = Math.round(process.memoryUsage().rss / 1048576); - cpuStr = ` cpu=${pct}%core rss=${rss}MB`; + const mem = process.memoryUsage(); + const rss = Math.round(mem.rss / 1048576); + const heap = Math.round(mem.heapUsed / 1048576); + const ext = Math.round(mem.external / 1048576); + const ab = Math.round((mem.arrayBuffers || 0) / 1048576); + cpuStr = ` cpu=${pct}%core rss=${rss}MB heap=${heap}MB ext=${ext}MB ab=${ab}MB`; _lastCpu = process.cpuUsage(); _lastCpuT = now; } catch {} + let gcStr = ''; + try { + gcStr = ` gc=${_gcCount} gcTotal=${_gcTotalMs.toFixed(0)}ms gcMax=${_gcMaxMs.toFixed(0)}ms`; + _gcCount = 0; _gcTotalMs = 0; _gcMaxMs = 0; + } catch {} let upStr = ''; try { if (uploadManager && typeof uploadManager.getDiagnostics === 'function') { @@ -225,7 +247,7 @@ function _maybeLogEventLoopDelay(activeJobs) { upStr = ` active-by-hoster={${byHoster}} transient-errs=${d.transientErrors || 0} pending=${d.pending || 0}`; } } catch {} - logInfo(`eventloop-delay active=${activeJobs} mean=${mean}ms p99=${p99}ms max=${max}ms stddev=${stddev}ms threadpool=${process.env.UV_THREADPOOL_SIZE}${cpuStr}${resStr}${upStr}`); + logInfo(`eventloop-delay active=${activeJobs} mean=${mean}ms p99=${p99}ms max=${max}ms stddev=${stddev}ms threadpool=${process.env.UV_THREADPOOL_SIZE}${cpuStr}${gcStr}${resStr}${upStr}`); _eventLoopDelay.reset(); } catch {} } diff --git a/package.json b/package.json index 7d0e75d..c092181 100644 --- a/package.json +++ b/package.json @@ -1,6 +1,6 @@ { "name": "multi-hoster-uploader", - "version": "3.3.96", + "version": "3.3.97", "description": "Upload files to doodstream, voe, vidmoly, byse simultaneously", "main": "main.js", "scripts": { diff --git a/tasks/lessons.md b/tasks/lessons.md index 5a1125f..bdb77ed 100644 --- a/tasks/lessons.md +++ b/tasks/lessons.md @@ -1,5 +1,20 @@ # Lessons +## 2026-06-21 — Histogram-Korrelation beweist KEINE Kausalrichtung; rss-Mathe als Sanity-Check +**Symptom:** ELD-Spikes korrelierten exakt mit hohem `FSReqCallback` (File-Reads in flight) → ich wollte +sofort ein Read-Concurrency-Semaphore über 5 Dateien bauen. +**Root cause / Korrektur (Advisor):** (1) Korrelation ≠ Kausalität: hohe in-flight-Reads können auch SYMPTOM +sein — ein aus ANDEREM Grund blockierter Loop drained die Read-Completions nicht, also stapeln sie sich im +Snapshot. (2) rss-Mathe widerlegte meine „Read-Buffer ballonen den Speicher"-These: 70 Streams × 256KB ≈ +18MB, aber rss schwang ~300MB → das ist Heap-/Objekt-Churn (GC), nicht die Read-Buffer. +**Regel:** Bevor ich auf Basis einer Histogramm-Korrelation einen Multi-File-Refactor baue: (a) Kausalrichtung +mit einem BILLIGEN reversiblen 1-Zeilen-Hebel testen (hier UV_THREADPOOL_SIZE 64→8), (b) die Größenordnung +gegenrechnen (passt die vermutete Quelle zahlenmäßig zur beobachteten Wirkung?), (c) den fehlenden Co-Faktor +(GC) erst MESSEN, bevor ich ihn aus- oder einschließe. Ein Build kann gleichzeitig Kandidaten-Fix UND +Diskriminator sein. +**Wie anwenden:** Bei „X korreliert mit Y, also fixe X": erst fragen „könnte Y → X statt X → Y?" und „passt +die Magnitude?". Wenn nein/unklar → erst der billige reversible Knopf + Messung, dann der teure Refactor. + ## 2026-04-21 — DOM-Doppelrender bei Bulk-State-Changes **Symptom:** User klickt auf "Erneut versuchen" mit 500+ Jobs → App hängt sekundenlang. **Root cause:** `retrySelectedJobs()` ruft `renderQueueTable + updateQueueActionButtons + updateStatusBar` auf, `startSelectedUpload()` ruft direkt danach genau dieselben Funktionen nochmal auf. diff --git a/tasks/todo.md b/tasks/todo.md index cbbea97..a492c75 100644 --- a/tasks/todo.md +++ b/tasks/todo.md @@ -1,3 +1,32 @@ +# v3.3.97 — DECISIVE ELD finding: file-read phase-flip + threadpool 64→8 + GC instrument + +The v3.3.96 `eventloop-delay` logs gave the decisive signal. At CONSTANT active-count, the system flips +between two regimes: +- HEALTHY (ELD ~11ms, rss 268–308MB): `SimpleWriteWrap ≈ active`, `FSReqCallback ≈ 0–1` (write/network-bound) +- BLOCKED (ELD 49–217ms, rss 540–610MB): `FSReqCallback ≈ active` (62–71 file reads in flight), `SimpleWriteWrap ≈ 0–4` +ELD spike + rss balloon both track `FSReqCallback` → file-read path through the libuv threadpool, NOT crypto, +NOT renderer, NOT GC-alone. All 5 uploaders read identically (256KB createReadStream); byse/dood/voe run +through the GENERIC uploadFile in hosters.js (no dedicated module). + +Advisor caveats baked into the build (do NOT skip on re-measure): +1. Causation UNPROVEN — high FSReqCallback could be a SYMPTOM (blocked loop can't drain read-completions). +2. rss math kills "read buffers ballooned": 70×256KB ≈ 18MB, but rss swings ~300MB → heap/object churn (GC). +3. Cheapest discriminator already wired: `UV_THREADPOOL_SIZE` 64→8 (1 line, reversible, NOT an upload cap; + 8×256KB reads ≈ 100MB/s ≫ 41MB/s aggregate). Suspect tp=64 made it WORSE (removed read-serialization). + +Shipped v3.3.97 = candidate-fix + discriminator in one build: +- main.js:1 `UV_THREADPOOL_SIZE` 64→8. +- ELD line now also logs `heap=`(heapUsed) `ext=`(external) `ab=`(arrayBuffers) `gc=`/`gcTotal=`/`gcMax=`ms + (PerformanceObserver entryTypes:['gc'], reset per window). + +DECISION RULE for the next user log: +- ELD drops with tp=8 → read over-parallelism confirmed → keep 8 or productionize a DEDICATED read-semaphore. +- ELD high + gcTotal/gcMax align with spikes → heap churn → hunt the allocator (semaphore would be wasted). +- ELD high + gc flat → causation reversed (symptom) → pivot. +WAIT for the next `eventloop-delay` log before any read-path refactor. NO upload cap (user rejected it). + +--- + # v3.3.94 — comprehensive measurement build (user: "mach alles messen was man messen kann") Localization so far (each step EMPIRICAL, not by elimination — advisor caught the elimination-leap):