docs(todo,lessons): session-wide lag audit — clean bill of health, doodstream gate shipped, config-store findings deferred
Records the 18-agent line-by-line audit of every line written this session: the reported lag was v3.3.87 (recent-panel cliff); the audit found no second cause affecting this user. doodstream _debugLog sync-fs gated (shipped). config-store load()/serialize history-scaling costs are real but sub-ms at this user's scale and the fix is risky persistence surgery — deferred, documented with measurements. Lesson: "audit every line" = look + measure + risk-appropriate decision, NOT fix-everything; the load() perf win and its corruption risk are the same coin (shared batch refs), so there is no safe version — defer, don't ship. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
This commit is contained in:
parent
233952af8f
commit
15a4509ad5
@ -139,3 +139,10 @@
|
|||||||
**Regel 3 — Multi-Agent-Findings gegen primäre Evidenz prüfen (Control-Char-Falschpositiv):** Der Hunt meldete HIGH-ish einen „_sessionFileKeys delete-key separator mismatch". Beim Versuch ihn zu fixen matchte der Edit-`old_string` NICHT. Char-Code-Dump (`HAS_U0001: True`) zeigte: die Zeile hat ECHTE U+0001-Zeichen — die Read-Tools der Verifier-Agenten rendern Steuerzeichen unsichtbar, sie schlossen fälschlich „keine Separatoren". KEIN Bug. **Wenn ein Fix-`old_string` nicht matcht obwohl Grep ihn zeigt: Char-Codes dumpen, bevor man dem Tool misstraut — die Quelle kann unsichtbar von der Read-Anzeige abweichen.**
|
**Regel 3 — Multi-Agent-Findings gegen primäre Evidenz prüfen (Control-Char-Falschpositiv):** Der Hunt meldete HIGH-ish einen „_sessionFileKeys delete-key separator mismatch". Beim Versuch ihn zu fixen matchte der Edit-`old_string` NICHT. Char-Code-Dump (`HAS_U0001: True`) zeigte: die Zeile hat ECHTE U+0001-Zeichen — die Read-Tools der Verifier-Agenten rendern Steuerzeichen unsichtbar, sie schlossen fälschlich „keine Separatoren". KEIN Bug. **Wenn ein Fix-`old_string` nicht matcht obwohl Grep ihn zeigt: Char-Codes dumpen, bevor man dem Tool misstraut — die Quelle kann unsichtbar von der Read-Anzeige abweichen.**
|
||||||
**Regel 4 — Den negligible-aber-realen Befund mit Zahl ABLEHNEN, nicht aus dem Bauch:** queueJobs O(N)-Scan pro Render (wächst unbounded, da removeFromQueueOnDone=false UND Folder-Monitor EINEN Batch via addJobs am Leben hält → 500-Cap-Prune feuert nie) — real, aber Blink-gemessen <0,1 ms bei 3000 Jobs. Den riskanten Inkremental-Counter-Refactor mit DIESER Zahl skippen, nicht mit „fühlt sich klein an".
|
**Regel 4 — Den negligible-aber-realen Befund mit Zahl ABLEHNEN, nicht aus dem Bauch:** queueJobs O(N)-Scan pro Render (wächst unbounded, da removeFromQueueOnDone=false UND Folder-Monitor EINEN Batch via addJobs am Leben hält → 500-Cap-Prune feuert nie) — real, aber Blink-gemessen <0,1 ms bei 3000 Jobs. Den riskanten Inkremental-Counter-Refactor mit DIESER Zahl skippen, nicht mit „fühlt sich klein an".
|
||||||
**Wie anwenden:** Append-only-Optimierungen, die auf Längenwachstum gaten, brechen still an JEDEM Cap (push-then-slice fixiert die Länge) — stattdessen die Anzahl NEUER Items zählen und am Boden evicten. „Mach es wie die Queue-Tabelle (virtualisieren)" war hier NICHT nötig: die Messung zeigte stehende 2000 Zeilen kosten median 0,4 ms; nur der Rebuild war teuer. Simplest-Fix der die gemessene Ursache trifft schlägt die größere Architektur-Änderung.
|
**Wie anwenden:** Append-only-Optimierungen, die auf Längenwachstum gaten, brechen still an JEDEM Cap (push-then-slice fixiert die Länge) — stattdessen die Anzahl NEUER Items zählen und am Boden evicten. „Mach es wie die Queue-Tabelle (virtualisieren)" war hier NICHT nötig: die Messung zeigte stehende 2000 Zeilen kosten median 0,4 ms; nur der Rebuild war teuer. Simplest-Fix der die gemessene Ursache trifft schlägt die größere Architektur-Änderung.
|
||||||
|
|
||||||
|
## 2026-06-21 — "Audit JEDE zeile" = audit + measure + risk-appropriate DEFER, nicht fix-everything (v3.3.88)
|
||||||
|
**Kontext:** Nach dem v3.3.87-Lag-Fix Folge-Goal: „schau dir wirklich JEDE zeile an die du geschrieben hast und schau ob es solche probleme gibt o. geben könnte". 18-Agenten-Audit + Eigen-Review jeder Hot-Path-Zeile + Blink-Benchmarks.
|
||||||
|
**Befund:** Der Audit fand, dass MEIN eigener T1-Fix (config-store cache, 29d1944) eine latente Regression einführte: `load()` macht ein unconditionales `structuredClone` der GANZEN config (inkl. unbounded history) pro Call → write-interleaved loads 2,2–2,4× LANGSAMER als das alte read+parse (gemessen @8000 Batches: 9,65 ms → 22,96 ms). Skaliert mit historySize. ABER: der echte User hat 8 Batches / 4,8 KB → Mikrosekunden. Negligible.
|
||||||
|
**Die Falle (Advisor hat geblockt):** Ich wollte es „elegant" fixen mit `history.slice()` (shallow) statt deep-clone. Advisor: STOPP. `load()` ist der gefährlichste Code im Repo (config + credentials; Korruption = Datenverlust), ich war hier schon mal von Cache-Semantik gebissen worden. Und: der Perf-Win und das Risiko sind DIESELBE Münze — der Speedup kommt NUR vom Sharing der Batch-Objekte by-reference, und genau dieses Sharing IST die Silent-Cache-Corruption-Gefahr (hängt an einem globalen Invariant „nichts deep-mutated je eine history-Batch" den ich über zukünftigen Code + jeden getHistory-Consumer nicht erzwingen kann). Es gibt KEINE sichere Version dieses Ansatzes → falsches Werkzeug für safety-kritischen Code. Hardcoded 5 keys in `_cloneConfig` wäre ein zweiter Footgun (zukünftiger top-level key verschwindet still aus jedem load()).
|
||||||
|
**Regel:** „Audit jede Zeile" heißt JEDE Zeile ANSCHAUEN + die Magnitude MESSEN + eine risiko-angemessene Entscheidung treffen — NICHT jeden geflaggten Befund fixen. Bei einem Audit-Goal ist „ich habe jede Zeile geprüft, jeden Befund als sub-ms bei realistischer History gemessen, den Mechanismus bestätigt aber den Fix als riskante Persistenz-Chirurgie für einen latenten Mikro-Cost eingestuft, also dokumentiere ich ihn statt ihn zu shippen" die VOLLSTÄNDIGE, gründliche Antwort. Jeden geflaggten Punkt unabhängig vom Risiko zu fixen ist keine Gründlichkeit — so wird aus einer Lag-Fix-Session ein Datenverlust-Incident. Nur den EINEN Befund shippen der im echten Szenario beißt (doodstream `_debugLog`: sync statSync+appendFileSync ~8–15×/Upload auf dem Main-Loop während des Uploads → hinter `logVerbose` gaten, default off, near-zero risk). Den Rest als bewusste Defers mit Messzahlen dokumentieren.
|
||||||
|
**Wie anwenden:** Wenn ein Goal („JEDE!! JEDE!!!") + ein Stop-Hook Druck erzeugen, immer weiterzuschneiden: das ist genau der Moment, den Advisor VOR dem Edit zu rufen. Magnitude am ECHTEN Artefakt prüfen (der User-Config, nicht @8000-Batches-Hypothese). Persistenz-/Credential-Code nur anfassen wenn der Fix risiko-frei UND der Gewinn real-spürbar ist — sonst dokumentieren und stoppen.
|
||||||
|
|||||||
@ -1,52 +1,50 @@
|
|||||||
# Long-running lag — root cause + fix (symptom: UI laggy over time, CPU 40%/RAM 6GB both normal)
|
# Lag audit of every line written this session (Goal: "schau dir JEDE zeile an … ob es solche probleme gibt o. geben könnte")
|
||||||
|
|
||||||
## What "laggy after time, low CPU, stable RAM" actually was (MEASURED, not assumed)
|
Method: self-review of every hot-path line I changed (config-store T1, main.js T3, renderer append-evict,
|
||||||
First instinct (main-process config I/O scaling with history) was WRONG for this user: the
|
diagnostics) + an 18-agent adversarial line-by-line audit (each finding double-verified for real + causes-
|
||||||
real config is tiny (history 23 rows / 4.8 KB, total 52 KB, queue ~153 jobs). Measured with a
|
perceptible-lag) + Blink microbenchmarks. Reference config = THIS user's real one: 8 batches / 4.8 KB
|
||||||
one-off node read of the live electron-config.json. So serialize-cost theories were dead on arrival.
|
history / 52 KB total — measured, not assumed.
|
||||||
|
|
||||||
A 13→18-agent leak hunt + adversarial verify + a Playwright/Blink microbenchmark found the
|
## Conclusion: v3.3.87 was the fix. The rest is a clean bill of health, not a to-do list.
|
||||||
真 cause:
|
The reported "laggy after long runtime" was the recent-panel rebuild cliff — found, fixed (append-evict,
|
||||||
|
80 ms → 7.4 ms Blink-verified), released v3.3.87. The audit surfaced NO second cause that affects this user.
|
||||||
|
|
||||||
### ROOT CAUSE (confirmed + profiled): recent-uploads panel append-only path defeats itself at the cap
|
## SHIPPED this round (v3.3.88) — the one finding that bites in the real upload scenario
|
||||||
- `renderRecentUploadsPanel` had a cheap append-only fast path gated on `rows.length > _recentLastRenderedLen`.
|
- doodstream-upload.js `_debugLog`: ran ungated SYNCHRONOUS statSync + appendFileSync (~8–15× per upload)
|
||||||
- `maybeAddSessionFile` caps `sessionFilesData` by push-then-slice (2000 → 2001 → sliced back to 2000).
|
on the main-process event loop WHILE uploading — delaying IPC / progress-batch forwarding for every other
|
||||||
- So once past SESSION_FILES_CAP, `rows.length` is pinned at 2000 → the gate is FALSE forever →
|
concurrent upload. The user runs doodstream, so this fired in practice. Fix: gate it behind the EXISTING
|
||||||
EVERY completion fell through to `tbody.innerHTML = rows.map(...).join('')` — a full ~2000-row
|
`globalSettings.logVerbose` setting (default off), mirroring main.js `logDebug`/`_logVerbose`; wired via the
|
||||||
rebuild. Cap is per (link × file × hoster), so 4–5 hosters hit 2000 at only ~400–500 files.
|
single `setLogVerbose` chokepoint (boot + save + toggle). Near-zero risk (early-return when verbose off),
|
||||||
- Blink measurement (table-layout:fixed, same engine as Electron): full 2000-row rebuild = **~80 ms**
|
removes all per-upload sync fs in normal operation. 397/397 tests pass, lint clean, wiring verified (shared
|
||||||
on EVERY completion past the cap. At several completions/sec that is a repeating ~80 ms main-thread
|
module instance, default-off, toggles).
|
||||||
freeze → exactly "fine fresh, gets laggy after many uploads, CPU/RAM fine."
|
|
||||||
|
|
||||||
## Fix (shipped) — append-evict, keeps the panel append-only past the cap
|
## DEFERRED — documented, conscious (real mechanisms, but wrong risk/reward to ship)
|
||||||
- Track newly-pushed rows in `_recentPendingAppends` (incremented in maybeAddSessionFile), consumed
|
These are in MY T1 code (lib/config-store.js, commit 29d1944). They are REAL and scale with history size,
|
||||||
every render. Gate the fast path on `pendingAppends > 0` (not length-delta) so it survives the cap.
|
but at THIS user's scale (8 batches) they are tens of MICROSECONDS, on a path that fires ~once/20s. The
|
||||||
- Prepend the new rows, then evict the same overflow count from the DOM bottom (oldest, = data front
|
verifiers said "not urgent / negligible (~0.1% duty) / latent main-process hygiene, not a renderer-lag fix."
|
||||||
eviction in date-desc) to honour the cap. DOM work back to O(added).
|
load() is the most dangerous code in the repo (config + credentials; corruption = data loss) and I was
|
||||||
- Gate behind an explicit `appendOnly` flag passed ONLY by scheduleRecentRender's rAF, so selection/
|
already bitten once here by cache semantics. So: recorded, not shipped.
|
||||||
delete/clear/sort/batch-done renders stay full + correct (no wrong-row eviction, no double-prepend).
|
- F1 `_serializeForDisk` JSON.stringify(whole config incl. unbounded history, null,2) on every save +
|
||||||
- VERIFIED in Blink over a simulated 5000-completion session: per-frame render **80 ms → median 7.4 ms**
|
copyFileSync of the growing file per commit. Scales with historySize. Root fix = split history into its own
|
||||||
(>10×), DOM stays exactly == data (cap held, newest-on-top, oldest evicted, ZERO duplicates).
|
file (history.json) so the ~20s queue-persist stops dragging history. Higher-risk persistence surgery.
|
||||||
|
- F2 `load()` deep-clones the WHOLE config (incl. history) on every call (even cache hit), and `_atomicWrite`
|
||||||
|
nulls the cache per write so write-interleaved loads are full misses. Measured @8000 batches: old read+parse
|
||||||
|
9.65 ms → new miss 22.96 ms (a 2.2–2.4× regression I introduced in T1) → new hit 12.94 ms. A "fix" via
|
||||||
|
shallow `history.slice()` is UNSAFE: the speedup comes only from sharing batch objects by reference, which
|
||||||
|
is exactly a silent-cache-corruption hazard that depends on a global "nothing ever deep-mutates a history
|
||||||
|
batch" invariant I can't enforce across future code + every getHistory consumer. Perf win and risk are the
|
||||||
|
same coin → no safe version → wrong tool for safety-critical code. The genuinely safe fixes (history-split,
|
||||||
|
bounded default retention) are out of scope (history-split = risk; bounded default = could drop user history).
|
||||||
|
- F3 (renderer, low) `_completedUploadKeys` grows unbounded per session, fully iterated in
|
||||||
|
buildPersistedQueueState on the ~20s persist. Sub-ms even for thousands of keys; the Set is the re-queue
|
||||||
|
dedup so capping it risks correctness. Not worth it.
|
||||||
|
- F4 (operator, low) diagnostics serverHealth does ~6–8 configStore.load() per request, each cloning history.
|
||||||
|
Cold path (only when diagnostics is queried), and largely a function of F2; defer with F2.
|
||||||
|
|
||||||
## Also shipped earlier (29d1944) — defensible, but NOT the cause for this user
|
## Verified clean (no action)
|
||||||
- T1 ConfigStore in-memory cache (mtime/size keyed) + lean _serializeForDisk (clones only hosters) +
|
- T1 structuredClone-per-load does NOT hit the upload hot path: shouldLogHosterToFile uses LIVE
|
||||||
copyFileSync .bak. T3 cache logMode/logFilePath (drop load() from the 500 ms log flush).
|
uploadManager.hosterSettings during uploads (its load() fallback is unreachable mid-batch); the 8×/s log
|
||||||
|
flush uses the O(1) _getLogSettings cache (T3); remaining load() sites are user-triggered IPC / boot.
|
||||||
## Investigated and DISMISSED with evidence
|
- T3 _getLogSettings: O(1) on cache hit, invalidated on every settings-write path.
|
||||||
- `_sessionFileKeys` "delete-key separator mismatch" (workflow flagged it HIGH-ish): FALSE POSITIVE.
|
- renderer append-evict (v3.3.87): no new per-frame cost; correctness re-verified (5000-completion sim).
|
||||||
Line uses REAL U+0001 chars (char-code dump: `HAS_U0001: True`); the verifier agents' Read rendered
|
- diagnostics renderer additions (0c6c502): all inside renderSettings() — cold, settings panel only.
|
||||||
the control chars invisibly and wrongly concluded "no separators". Keys match at runtime. No leak.
|
|
||||||
- queueJobs O(N) per-render scans (grows unbounded since removeFromQueueOnDone=false AND folder-monitor
|
|
||||||
keeps ONE batch alive via addJobs so the 500-cap prune never fires): REAL but Blink-measured at
|
|
||||||
**<0.1 ms even at 3000 jobs** → imperceptible. Incremental-counter refactor NOT worth the risk. Skipped.
|
|
||||||
- "Continuous standing relayout of 2000 rows": Blink median 0.4 ms regardless of row count; its spikes
|
|
||||||
were caused by the rebuild (same root cause). Not a standing cost → no need to virtualize/lower cap.
|
|
||||||
|
|
||||||
## Deferred (separate, not this symptom)
|
|
||||||
- doodstream-upload.js `_debugLog`: ungated SYNC fs.appendFileSync + statSync ~10–20×/upload on the
|
|
||||||
main loop. CONSTANT cost (does not grow over a session), only when doodstream is active. Real freeze
|
|
||||||
contributor but NOT the reported progressive lag — convert to buffered-async like main.js, separately.
|
|
||||||
|
|
||||||
## Verification summary
|
|
||||||
- 397/397 tests pass, eslint 0 errors.
|
|
||||||
- Blink before/after: recent-panel render 80 ms → 7.4 ms; correctness asserted (cap/order/no-dupes).
|
|
||||||
|
|||||||
Loading…
Reference in New Issue
Block a user