From c5daee25af54e7b5d15d4b3b0f1d352b46d2d19b Mon Sep 17 00:00:00 2001 From: sascha Date: Fri, 7 Aug 2026 13:50:01 +0200 Subject: [PATCH] fix(diar): sherpa abschnittsweise laufen lassen (OOM bei langen Aufnahmen) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Der sherpa-Diarisierungslauf brauchte RAM quadratisch zur Gesprächslänge (gemessen 349 MB bei 10 min, 1389 MB bei 20 min, 2643 MB bei 30 min). Die 54-min-Aufnahme #99 riss 5,4 GB, wurde OOM-getötet und nahm wegen OOMPolicy=stop die ganze App mit — in der GUI "Transkription fehlgeschlagen" und "failed to fetch". Die v2-Pipeline verwirft sherpas Labels und nutzt nur die Turn-Grenzen, also laeuft der Pass jetzt in 600-s-Abschnitten (je +-5 s Kontext) und die Grenzen werden mit Zeit-Offset zusammengesetzt. Zusätzlich OOMPolicy=continue, damit ein OOM-getöteter Helfer die App nicht mehr stoppt. Verifiziert an #99: sherpa-Spitze 363 MB, 726 Turns, 8 Sprecher, Analyse vollstaendig (done/done). --- app/diar.js | 68 ++++++++++++++++--- docs/04-diarization.md | 62 ++++++++++++++++- docs/08-changelog.md | 37 ++++++++++ .../systemd/system/callrec.service.d/oom.conf | 6 ++ 4 files changed, 161 insertions(+), 12 deletions(-) create mode 100644 system/etc/systemd/system/callrec.service.d/oom.conf diff --git a/app/diar.js b/app/diar.js index 3041e9f..6be671a 100644 --- a/app/diar.js +++ b/app/diar.js @@ -36,11 +36,11 @@ const MIN_TOTAL_SEC = +(process.env.DIAR_MIN_TOTAL_SEC || 20); // 40 min). The old fixed 10-min timeout killed every recording over ~11 min and // surfaced as an opaque "Command failed" (only sherpa's argv echo in stderr). // Scale the timeout with the audio length: ~2.5x its duration, floor 20 min. -function diarTimeoutMs(wavPath) { - let sec = 0; - try { sec = Math.max(0, (fs.statSync(wavPath).size - 44) / 32000); } catch {} // 16kHz mono s16 - return Math.max(20 * 60 * 1000, Math.ceil(sec * 2.5) * 1000); +function wavSec(wavPath) { + try { return Math.max(0, (fs.statSync(wavPath).size - 44) / 32000); } catch { return 0; } // 16kHz mono s16 } +function diarTimeoutMs(wavPath) { return timeoutForSec(wavSec(wavPath)); } +function timeoutForSec(sec) { return Math.max(20 * 60 * 1000, Math.ceil(sec * 2.5) * 1000); } const DIR = '/opt/sherpa/sherpa-onnx-v1.13.3-linux-aarch64-shared-cpu'; const BIN = `${DIR}/bin/sherpa-onnx-offline-speaker-diarization`; @@ -98,12 +98,26 @@ const COS_FINAL_MAX = +(process.env.DIAR_COS_FINAL_MAX || 0.35); // want fine turn boundaries (and min-duration-off=0 so adjacent turns of the // same label are NOT glued together). const FINE_THRESHOLD = process.env.DIAR_FINE_THRESHOLD || '0.2'; +// sherpa keeps the whole recording plus its clustering state in RAM, and the +// peak grows QUADRATICALLY with the audio length — measured on #99 at 1.6 GHz: +// 10 min → 349 MB (130 turns, 130 s wall) +// 20 min → 1389 MB (242 turns, 300 s wall) = 4x RAM for 2x audio +// 30 min → 2643 MB (361 turns, 459 s wall) +// so the 54-min #99 hit 5.4 GB, the kernel OOM-killer took sherpa out and +// systemd's default OOMPolicy=stop tore the whole app down with it (GUI: +// "Transkription fehlgeschlagen" + "failed to fetch"). +// v2 throws sherpa's LABELS away and keeps only the pyannote turn BOUNDARIES, so +// the pass can run on slices whose boundaries are stitched back with an offset — +// the footprint then stays at one slice's level no matter how long the call is, +// and because the cost is quadratic it is also FASTER (6x 130 s beats one +// 54-min run). Cost: a turn crossing a seam is cut in two; the re-clustering +// gives both halves the same speaker anyway. DIAR_CHUNK_SEC=0 disables chunking. +const CHUNK_SEC = process.env.DIAR_CHUNK_SEC != null ? +process.env.DIAR_CHUNK_SEC : 600; +const CHUNK_CTX_SEC = 5; -// Raw sherpa turns. mode 'fine' = boundaries only (v2), else the legacy call -// with its own clustering (threshold or pinned count). -async function sherpaTurns(wavPath, numSpeakers, fine) { - const clusterArg = fine ? `--clustering.cluster-threshold=${FINE_THRESHOLD}` - : (numSpeakers > 0 ? `--clustering.num-clusters=${numSpeakers}` : `--clustering.cluster-threshold=${THRESHOLD}`); +// One sherpa call over a whole wav file. `fine` = boundaries only (v2), else the +// legacy call with its own clustering (threshold or pinned count). +async function sherpaRun(wavPath, clusterArg, fine, timeoutMs) { const args = [ 'taskset', '-c', '4-7', BIN, `--segmentation.pyannote-model=${SEG}`, @@ -114,7 +128,7 @@ async function sherpaTurns(wavPath, numSpeakers, fine) { ...(fine ? ['--min-duration-on=0.2', '--min-duration-off=0.0'] : []), wavPath, ]; - const { stdout } = await pexec(args[0], args.slice(1), { env: env(), maxBuffer: 1 << 22, timeout: diarTimeoutMs(wavPath) }); + const { stdout } = await pexec(args[0], args.slice(1), { env: env(), maxBuffer: 1 << 22, timeout: timeoutMs }); const segs = []; for (const line of stdout.split('\n')) { const m = line.match(/([\d.]+)\s*--\s*([\d.]+)\s*(speaker_\d+)/); @@ -124,6 +138,40 @@ async function sherpaTurns(wavPath, numSpeakers, fine) { return segs; } +// Raw sherpa turns, chunked on long recordings (see CHUNK_SEC). +async function sherpaTurns(wavPath, numSpeakers, fine) { + const clusterArg = fine ? `--clustering.cluster-threshold=${FINE_THRESHOLD}` + : (numSpeakers > 0 ? `--clustering.num-clusters=${numSpeakers}` : `--clustering.cluster-threshold=${THRESHOLD}`); + const dur = wavSec(wavPath); + // The legacy pass needs ONE global clustering, so it can never be chunked. + if (!fine || !CHUNK_SEC || dur <= CHUNK_SEC * 1.25) { + return sherpaRun(wavPath, clusterArg, fine, timeoutForSec(dur)); + } + const wav = loadWav(wavPath); + const tmp = `/tmp/diarchunk_${process.pid}.wav`; + const out = []; + try { + for (let t0 = 0; t0 < dur; t0 += CHUNK_SEC) { + const t1 = Math.min(dur, t0 + CHUNK_SEC); + // Context on both sides: pyannote decides on a sliding 10 s window, so a + // hard cut would blur the turns right at the seam. + const a = Math.max(0, t0 - CHUNK_CTX_SEC), b = Math.min(dur, t1 + CHUNK_CTX_SEC); + writeSlice(wav, a, b, tmp); + const segs = await sherpaRun(tmp, clusterArg, fine, timeoutForSec(b - a)); + let kept = 0; + for (const s of segs) { + // Keep only what belongs to THIS chunk's own range (the context is + // already covered by its neighbour) and shift into absolute time. + const start = Math.max(t0, s.start + a), end = Math.min(t1, s.end + a); + if (end - start >= 0.1) { out.push({ start, end, speaker: s.speaker }); kept++; } + } + console.log(`diar: sherpa-Abschnitt ${Math.round(t0)}-${Math.round(t1)}s → ${kept} Turns`); + } + } finally { try { fs.unlinkSync(tmp); } catch {} } + out.sort((x, y) => x.start - y.start); + return out; +} + // Returns [{ start, end, speaker }] (seconds, speaker = "speaker_00"…). // numSpeakers > 0 fixes the count when the user knows it, otherwise the count // is found automatically (people can join/leave a conference call). diff --git a/docs/04-diarization.md b/docs/04-diarization.md index e846fda..f74af16 100644 --- a/docs/04-diarization.md +++ b/docs/04-diarization.md @@ -141,6 +141,64 @@ sitzt einer sicher darauf, wirkt der Name wie ein Marker-Tag = cannot-link. widersprechenden Stimmabdruck (`identify #id: Stimmabdruck "X" schlägt unsicheren Marker "Y"`). In #79 hatte der Marker bei 6,6 s Saschas Cluster „Markus" getauft. +## Abschnittsweiser sherpa-Lauf (seit 2026-08-07) — der RAM-Bedarf wuchs quadratisch + +**Symptom:** Aufnahme #99 (53:56) endete mit „Transkription fehlgeschlagen“, die GUI zeigte +„failed to fetch“. In Wahrheit war die Transkription längst fertig (8666 Wörter, RTF 0,394); +gestorben ist der sherpa-Lauf danach: + +``` +Out of memory: Killed process 3107072 (sherpa-onnx-off) total-vm:8387852kB, anon-rss:5463416kB +callrec.service: A process of this unit has been killed by the OOM killer. +callrec.service: Failed with result 'oom-kill'. +``` + +**Gemessen** (gleiche Aufnahme, Anfangsstücke verschiedener Länge, A76 auf 1,608 GHz, `VmHWM`): + +| Audio | Spitzen-RSS | Turns | Laufzeit | +|---|---|---|---| +| 10 min | 349 MB | 130 | 130 s | +| 20 min | 1389 MB | 242 | 300 s | +| 30 min | 2643 MB | 361 | 459 s | +| 54 min | **5,4 GB → OOM** | — | Abbruch nach ~14 min | + +Doppelte Länge = **vierfacher** Speicher: sherpa hält das ganze Gespräch plus seinen Clustering-Zustand +im RAM (O(n²) über die Turns). Auf 8 GB ohne echten Swap (nur zram) ist damit bei ~45 min Schluss. + +**Fix:** v2 wirft sherpas **Labels** ohnehin weg und braucht nur die **Turn-Grenzen** — also läuft der +Lauf jetzt in Abschnitten von 600 s (`DIAR_CHUNK_SEC`, `0` schaltet ab) und die Grenzen werden mit +Zeit-Offset zusammengesetzt. Der Speicher bleibt damit auf dem Niveau eines Abschnitts, **unabhängig +von der Gesprächslänge** — und weil die Kosten quadratisch waren, ist es zusätzlich schneller +(6 × ~150 s statt eines Laufs, der nach 14 min noch nicht fertig war). + +```mermaid +flowchart LR + WAV["WAV 54 min"] --> CUT["PCM-Slicing in 600-s-Abschnitte
je ±5 s Kontext
(pyannote schaut über 10-s-Fenster)"] + CUT --> S1["sherpa Abschnitt 1
0–600 s"] + CUT --> S2["sherpa Abschnitt 2
600–1200 s"] + CUT --> SN["… Abschnitt n"] + S1 --> CLIP["nur Turns im EIGENEN Bereich behalten,
auf ihn beschneiden, + t0 verschieben"] + S2 --> CLIP + SN --> CLIP + CLIP --> ALL["Turn-Grenzen der ganzen Aufnahme
(#99: 726 Turns)"] + ALL --> V2["weiter wie Pipeline v2
(Fenster → Embeddings → AHC)"] +``` + +- Kontext von ±5 s pro Abschnitt, damit die Naht die Grenzerkennung nicht verwischt; die Turns des + Kontexts gehören dem Nachbar-Abschnitt und werden verworfen. +- **Preis:** ein Turn, der genau auf einer Naht liegt, wird in zwei geteilt. Das Re-Clustering vergibt + beiden Hälften ohnehin denselben Sprecher — bei 600 s Abschnittslänge sind das ≤ 5 Nähte pro Stunde. +- Der **Legacy-Pfad** (`DIAR_MODE=legacy`) läuft weiter unzerteilt: er braucht sherpas eigenes, + globales Clustering und lässt sich nicht abschnittsweise rechnen. +- **Zweite Sicherung:** `OOMPolicy=continue` (Drop-in `system/etc/systemd/system/callrec.service.d/oom.conf`). + systemd stoppt eine Unit per Default komplett, sobald *ein* Kindprozess OOM-getötet wird — genau das + riss die App mit (daher „failed to fetch“). Diarisierung und Analyse sind im Code bereits nicht-fatal, + also überlebt die App jetzt einen OOM-getöteten Helfer und behält Transkript + Aufnahme. + +**Verifiziert** an #99 (Re-Diarisierung 2026-08-07): 6 Abschnitte, Spitzen-RSS **363 MB** statt 5,4 GB, +726 Turns → 1932 Fenster → **8 Sprecher**, 6 Live-Marker verankert, Diarisierung 13,5 min, keine +OOM-Meldung. + ## Harte Grenzen / Sackgassen - **Überlappendes gleichzeitiges Sprechen** ist mit Mono-Mix prinzipiell nicht trennbar. @@ -148,8 +206,8 @@ hatte der Marker bei 6,6 s Saschas Cluster „Markus" getauft. - sherpa-Quantisierung q5_0: langsamer UND schlechter auf diesem aarch64-Build — tot. - Wer im ganzen Gespräch weniger als `min(20 s, 2 % der Sprechzeit)` redet, wird einem anderen Sprecher zugeschlagen (Weak-Fold) — sonst überleben Übersprech-Fragmente als „Sprecher". -- Diarization-Timeout skaliert mit Dauer (`diarTimeoutMs()` = Dauer × 2,5, min. 20 min). - (`parse-options.cc:373`-Ausgabe ist harmloses argv-Echo.) +- Diarization-Timeout skaliert mit Dauer (`timeoutForSec()` = Dauer × 2,5, min. 20 min — bei + abschnittsweisem Lauf pro Abschnitt). (`parse-options.cc:373`-Ausgabe ist harmloses argv-Echo.) - **v1 ist nicht weg:** `DIAR_MODE=legacy` schaltet auf die alte Anchor-Merge-Konsolidierung zurück (`consolidateSpeakers()` bleibt als Fallback, wenn die v2-Fenster-Embeddings scheitern). diff --git a/docs/08-changelog.md b/docs/08-changelog.md index 375b325..fa49c31 100644 --- a/docs/08-changelog.md +++ b/docs/08-changelog.md @@ -3,6 +3,43 @@ Chronik der Entwicklungsschritte. **Regel: jede zukünftige Änderung bekommt hier einen Eintrag** (Datum, Was, Warum, betroffene Dateien/Backups). +## 2026-08-07 — Lange Aufnahmen scheiterten: sherpa-Diarisierung lief in den OOM-Killer + +**Symptom:** Aufnahme #99 (53:56) endete mit „Transkription fehlgeschlagen“ (Badge „KI-Fehler“), beim +Abruf der Analyse zeigte die GUI „failed to fetch“. Verdacht lag auf dem eMMC-Umzug vom 2026-08-03 — +**war es nicht**: Speicher-Setup (zram 3,9 GB, kein Swapfile), RAM (7,83 GB) und `armbian-zram-config` +sind vor und nach dem Umzug identisch (alte SD-Root gegengeprüft). + +**Tatsächliche Ursache** (aus `dmesg`): die Transkription war längst fertig (8666 Wörter, RTF 0,394), +gestorben ist der sherpa-Lauf danach — +`Out of memory: Killed process (sherpa-onnx-off) … anon-rss:5463416kB`. Und weil systemd eine Unit per +Default komplett stoppt, sobald ein Kindprozess OOM-getötet wird (`OOMPolicy=stop`), riss das die ganze +App mit: `callrec.service: Failed with result 'oom-kill'` → abgebrochene Analyse, leerer Fetch im +Browser. Warum es früher ging: der RAM-Bedarf wächst **quadratisch** mit der Gesprächslänge — gemessen +349 MB (10 min), 1389 MB (20 min), 2643 MB (30 min), 5,4 GB (54 min). Bis ~45 min passt es, danach nicht. + +**Fix 1 (Ursache):** sherpa läuft jetzt in Abschnitten von 600 s (`DIAR_CHUNK_SEC`, `0` = aus), je mit +±5 s Kontext; die Turn-Grenzen werden mit Zeit-Offset zusammengesetzt. Zulässig, weil die v2-Pipeline +sherpas Labels ohnehin verwirft und nur die Grenzen nutzt. Speicher bleibt damit dauerhaft auf +Abschnitts-Niveau und der Lauf ist zusätzlich schneller (quadratische Kosten). + +**Fix 2 (Schadensbegrenzung):** `OOMPolicy=continue` — ein OOM-getöteter Helfer (sherpa/whisper/rkllm) +darf die App nicht mehr mitreißen; Diarisierung und Analyse sind im Code bereits nicht-fatal. + +**Verifiziert an #99** (Re-Transkription + Re-Diarisierung, 2026-08-07): sherpa-Spitze **363 MB** statt +5,4 GB, 6 Abschnitte (131/103/119/160/158/55 Turns) → 726 Turns → 1932 Fenster → **8 Sprecher**, alle +6 Live-Marker verankert und alle 8 Sprecher benannt (Fabio Haase, Merle, Dennis, Nico, Lisa, Kai, Kim, +Artur), Transkript 51.406 Zeichen, Zusammenfassung 15.930 Zeichen, 20 LLM-Abschnitte, Analyse 5073 s, +189 Passagen indexiert, `status=done` / `analysis_status=done`, kein Neustart, kein OOM, 64,7 °C. + +Dateien: `app/diar.js` (Board-Backup `diar.js.bak-chunk`), +`system/etc/systemd/system/callrec.service.d/oom.conf` (neu), Kapitel +[04 – Sprechertrennung](04-diarization.md). + +**Nebenbefund (offen):** während der Analyse belegt `rkllm_server` 6,5 GB RSS (NPU-Modell, shared) und +das System hat nur noch ~100 MB frei — funktioniert, aber ohne Reserve. Wenn wieder etwas OOM-nah +wird, ist das der Kandidat. + ## 2026-08-03 — System von der SD-Karte auf die eMMC umgezogen **Warum:** alles lag auf der SD-Karte (System, Datenbank, Aufnahmen, Modelle), die verlötete eMMC lag diff --git a/system/etc/systemd/system/callrec.service.d/oom.conf b/system/etc/systemd/system/callrec.service.d/oom.conf new file mode 100644 index 0000000..aece5e0 --- /dev/null +++ b/system/etc/systemd/system/callrec.service.d/oom.conf @@ -0,0 +1,6 @@ +# Ein OOM-getoetetes Kind (sherpa/whisper/rkllm) darf nicht die ganze App +# mitreissen: systemd stoppt die Unit sonst per Default (OOMPolicy=stop), die +# laufende Analyse stirbt und das Frontend sieht "failed to fetch". +# Diarisierung/Analyse sind im Code bereits nicht-fatal. +[Service] +OOMPolicy=continue